Wafl clean stalling

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Wafl clean stalling

Fred Grieco
I had this issue twice now on two different systems.  There will be "sudden" high latency, across the board. Oncommand performance manager will have a some disk layout warnings, and tons of latency warnings with no clear shark.  Grafana stats will show high "Wall write cleaning" utilization.  Sysstat shows slow flushing CPs with a lot of "s" type... Special files.  

First time (3250 8.2.3p5 cdot) I had to do a takeover just to break the spell, latency and cpu were so bad.  Second time was on a fas8080 8.3.1, so a little more robust.  In this case, wafl scan stats showed a long, stalled snap create summary (see bottom, outputs on same color several min apart).  This is a Snapmirror source, and aborting the sm processes on the dest fixed the problem and eliminated the snap create wafl scan, even though they were completing regularly (though slowly). 

The only common denominator here is both of these systems use flashpool.  

Has anyone seen this before?  I'm really baffled that the sm abort fixed the issue on the source.  I have a case open with support and so far they are saying "lots of Snapmirror processes" but it's really only about 20...

Thanks, 
Fred 

CPU    NFS   CIFS   HTTP   Total     Net   kB/s    Disk   kB/s    Tape   kB/s  Cache  Cache    CP  CP  Disk   OTHER    FCP  iSCSI     FCP   kB/s   iSCSI   kB/s
                                                     in    out    read  write    read  write    age    hit  time  ty  util                            in    out      in    out
29%   1309      0      0    2644     747  10568  450806 363535       0      0     0s    92%  100%  :s   31%     123   1212      0   43230 172098       0      0
18%    278      0      0    2286     435  55557  238412 105938       0      0     0s    94%  100%  :s   10%     838   1170      0   47435 103353       0      0
14%    357      0      0    1278     527  13516  110072  20700       0      0     1     94%  100%  :s    9%     214    707      0   20912  59405       0      0
17%    506      0      0    3171     611  55294  220118  43358       0      0     0s    93%  100%  :s   10%    1052   1613      0   33894 144762       0      0
17%    475      0      0    2025     415  33509  230281  43878       0      0     1     93%  100%  :f   14%     587    963      0   20764 109122       0      0
16%    525      0      0    2167     289   4638   78980     62       0      0     1     92%  100%  :v    7%     326   1316      0   33645  67102       0      0
24%    766      0      0    2069     681   4712  289509 157377       0      0     0s    94%   93%  Zn   16%     289   1014      0   30442  67344       0      0
18%    232      0      0    1518     387  30691  217187 205447       0      0     0s    94%  100%  :s   18%     615    671      0    4686  92926       0      0
18%    302      0      0    1830     593  29273  211516 112819       0      0     0s    94%  100%  :s   11%     577    951      0   13343  94976       0      0
16%    404      0      0    1381     248   1508   74363  51789       0      0     1s    95%  100%  :s    6%     144    833      0   18491  66701       0      0
15%    250      0      0    1437     362  25192  127166  14783       0      0     0s    95%  100%  :s   13%     469    718      0    5478  64261       0      0
15%    272      0      0    1315     289  26669   75965      7       0      0     0s    95%  100%  :s    5%     488    555      0    9930  56409       0      0
15%    362      0      0    1352     384   9242  126759  56523       0      0     1     92%  100%  :s    5%     224    766      0    4169  61645       0      0
17%    393      0      0    1667     527  41316  162630      0       0      0     0s    93%  100%  :s   14%     683    591      0    2742  91873       0      0
13%    489      0      0    1847     382  22543  126444      0       0      0     0s    91%  100%  :s   10%     416    942      0   13912  98668       0      0
12%    466      0      0    1576     267   1942  125502     22       0      0   >60     92%  100%  :s    8%      75   1035      0   25502 105575       0      0
19%    648      0      0    2236     616  12843  180895      7       0      0     1     91%  100%  :f   13%     259   1329      0   20573 112682       0      0
17%    589      0      0    2648     732  40612  165832  43495       0      0     1     93%  100%  :v   16%     662   1397      0   30105  84571       0      0
13%    298      0      0    1494     224   5258   75630     47       0      0     0s    91%  100%  :v   19%      93   1103      0   37230  59553       0      0
25%    961      0      0    2517     611   7662  293316 228741       0      0     0s    95%   93%  Zs   24%      70   1486      0   28444  64059       0      0
CPU    NFS   CIFS   HTTP   Total     Net   kB/s    Disk   kB/s    Tape   kB/s  Cache  Cache    CP  CP  Disk   OTHER    FCP  iSCSI     FCP   kB/s   iSCSI   kB/s
                                       in    out    read  write    read  write    age    hit  time  ty  util                            in    out      in    out
18%    713      0      0    1802     308   4102  139025 138664       0      0     1s    93%  100%  :s   17%     106    983      0   12370  67131       0      0
18%    653      0      0    2290     356   3024  175784 114858       0      0     0s    93%  100%  :s   17%     103   1534      0   30419 103879       0      0
14%    277      0      0    1117     264    835   96862  48373       0      0     0s    93%  100%  :s   16%     168    672      0   12616  68979       0      0
13%    465      0      0    1236     616   1505   56551     19       0      0     0s    94%  100%  :s   13%     150    621      0   10984  51964       0      0
13%    363      0      0    1184     359    724   47141      6       0      0     1     93%  100%  :s   14%     175    646      0   15597  41360       0      0
16%    394      0      0    1192     330   1622  150649  62399       0      0     0s    93%  100%  :s   21%     149    649      0   13094  89017       0      0
16%   1660      0      0    2609    1180   3836  101862     22       0      0     1     88%  100%  :s   15%     203    746      0   12464  58093       0      0
15%   2306      0      0    3503    1574  23707  144890      0       0      0     0s    93%  100%  :s   17%     442    755      0   11702  95250       0      0
14%   1118      0      0    2256     570  30514   97837  33885       0      0     1     95%  100%  :f   10%     612    526      0    9866  54222       0      0
14%   3636      0      0    4489    1649   7360   70514     66       0      0     1     92%  100%  :v    7%     238    615      0   10162  56678       0      0
13%   3540      0      0    4277    1615   2594   63757      0       0      0     1s    91%  100%  :v    6%     129    608      0   14768  48771       0      0
16%   2842      0      0    4097    1682  20595  137085     22       0      0     1     93%  100%  :v   14%     416    839      0   14408  78167       0      0
15%   2544      0      0    3760    1540  37961  125949      0       0      0     0s    94%  100%  :v   10%     692    524      0   10924 100674       0      0
26%   2493      0      0    4307     991   9312  275089 153829       0      0     0s    94%   90%  Zs   22%     329   1485      0   44023 126413       0      0
16%   1624      0      0    2577    1154   3959  179468  99585       0      0     0s    93%  100%  :s   20%     145    808      0   20926  89793       0      0
19%   2543      0      0    4807    2015  59604  258735  76443       0      0     0s    94%  100%  :s   17%    1042   1222      0   30911 147132       0      0
18%   3354      0      0    4264    1452   1771  189401  92019       0      0     0s    94%  100%  :s    7%      93    817      0   14723  84496       0      0
13%   3561      0      0    4435    1553   1027   99965  47137       0      0     0s    93%  100%  :s    6%     101    773      0   10691  82650       0      0
18%   2808      0      0    3998    1687   6156  174923    125       0      0     1     92%  100%  :s   14%     216    974      0   19335 117237       0      0
18%   4372      0      0    6370    2245  55867  242723  67036       0      0     0s    94%  100%  :s   10%    1019    979      0   19915 133940       0      0
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19501 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 3 of 21127
11363427    block ownership calculation     block 6400 of 21126
11363428     blocks used summary update     block 889 of 21127
 
 
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19501 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 5 of 21127
11363427    block ownership calculation     block 6500 of 21126
11363428     blocks used summary update     block 2096 of 21127
 
 
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19502 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 4 of 21127 (fbn 211)
11363427    block ownership calculation     block 7100 of 21126
11363428     blocks used summary update     block 2799 of 21127 (fbn 3952)
 
 
 
 
This e-mail and its attachments are intended only for the individual or entity to whom it is addressed and may contain information that is confidential, privileged, inside information, or subject to other restrictions on use or disclosure. Any unauthorized use, dissemination or copying of this transmission or the information in it is prohibited and may be unlawful. If you have received this transmission in error, please notify the sender immediately by return e-mail, and permanently delete or destroy this e-mail, any attachments, and all copies (digital or paper). Unless expressly stated in this e-mail, nothing in this message should be construed as a digital or electronic signature. For additional important disclaimers and disclosures regarding KCG’s products and services, please click on the following link:

http://www.kcg.com/legal/global-disclosures

_______________________________________________
Toasters mailing list
[hidden email]
http://www.teaparty.net/mailman/listinfo/toasters
Reply | Threaded
Open this post in threaded view
|

Re: Wafl clean stalling

Fred Grieco
Update on this -- this is actually a bug specific to thin-provisioned volumes and flashpool.   There is an issue deleting snapshots.   In this case, it was deleting the oldest on a schedule, and wafl scan was showing snap creation (btw, is there a separate wafl scan line or other evidence of active snap deletion?)




From: Fred Grieco <[hidden email]>
To: Toasters <[hidden email]>
Sent: Wednesday, April 5, 2017 8:23 PM
Subject: Wafl clean stalling

I had this issue twice now on two different systems.  There will be "sudden" high latency, across the board. Oncommand performance manager will have a some disk layout warnings, and tons of latency warnings with no clear shark.  Grafana stats will show high "Wall write cleaning" utilization.  Sysstat shows slow flushing CPs with a lot of "s" type... Special files.  

First time (3250 8.2.3p5 cdot) I had to do a takeover just to break the spell, latency and cpu were so bad.  Second time was on a fas8080 8.3.1, so a little more robust.  In this case, wafl scan stats showed a long, stalled snap create summary (see bottom, outputs on same color several min apart).  This is a Snapmirror source, and aborting the sm processes on the dest fixed the problem and eliminated the snap create wafl scan, even though they were completing regularly (though slowly). 

The only common denominator here is both of these systems use flashpool.  

Has anyone seen this before?  I'm really baffled that the sm abort fixed the issue on the source.  I have a case open with support and so far they are saying "lots of Snapmirror processes" but it's really only about 20...

Thanks, 
Fred 

CPU    NFS   CIFS   HTTP   Total     Net   kB/s    Disk   kB/s    Tape   kB/s  Cache  Cache    CP  CP  Disk   OTHER    FCP  iSCSI     FCP   kB/s   iSCSI   kB/s
                                                     in    out    read  write    read  write    age    hit  time  ty  util                            in    out      in    out
29%   1309      0      0    2644     747  10568  450806 363535       0      0     0s    92%  100%  :s   31%     123   1212      0   43230 172098       0      0
18%    278      0      0    2286     435  55557  238412 105938       0      0     0s    94%  100%  :s   10%     838   1170      0   47435 103353       0      0
14%    357      0      0    1278     527  13516  110072  20700       0      0     1     94%  100%  :s    9%     214    707      0   20912  59405       0      0
17%    506      0      0    3171     611  55294  220118  43358       0      0     0s    93%  100%  :s   10%    1052   1613      0   33894 144762       0      0
17%    475      0      0    2025     415  33509  230281  43878       0      0     1     93%  100%  :f   14%     587    963      0   20764 109122       0      0
16%    525      0      0    2167     289   4638   78980     62       0      0     1     92%  100%  :v    7%     326   1316      0   33645  67102       0      0
24%    766      0      0    2069     681   4712  289509 157377       0      0     0s    94%   93%  Zn   16%     289   1014      0   30442  67344       0      0
18%    232      0      0    1518     387  30691  217187 205447       0      0     0s    94%  100%  :s   18%     615    671      0    4686  92926       0      0
18%    302      0      0    1830     593  29273  211516 112819       0      0     0s    94%  100%  :s   11%     577    951      0   13343  94976       0      0
16%    404      0      0    1381     248   1508   74363  51789       0      0     1s    95%  100%  :s    6%     144    833      0   18491  66701       0      0
15%    250      0      0    1437     362  25192  127166  14783       0      0     0s    95%  100%  :s   13%     469    718      0    5478  64261       0      0
15%    272      0      0    1315     289  26669   75965      7       0      0     0s    95%  100%  :s    5%     488    555      0    9930  56409       0      0
15%    362      0      0    1352     384   9242  126759  56523       0      0     1     92%  100%  :s    5%     224    766      0    4169  61645       0      0
17%    393      0      0    1667     527  41316  162630      0       0      0     0s    93%  100%  :s   14%     683    591      0    2742  91873       0      0
13%    489      0      0    1847     382  22543  126444      0       0      0     0s    91%  100%  :s   10%     416    942      0   13912  98668       0      0
12%    466      0      0    1576     267   1942  125502     22       0      0   >60     92%  100%  :s    8%      75   1035      0   25502 105575       0      0
19%    648      0      0    2236     616  12843  180895      7       0      0     1     91%  100%  :f   13%     259   1329      0   20573 112682       0      0
17%    589      0      0    2648     732  40612  165832  43495       0      0     1     93%  100%  :v   16%     662   1397      0   30105  84571       0      0
13%    298      0      0    1494     224   5258   75630     47       0      0     0s    91%  100%  :v   19%      93   1103      0   37230  59553       0      0
25%    961      0      0    2517     611   7662  293316 228741       0      0     0s    95%   93%  Zs   24%      70   1486      0   28444  64059       0      0
CPU    NFS   CIFS   HTTP   Total     Net   kB/s    Disk   kB/s    Tape   kB/s  Cache  Cache    CP  CP  Disk   OTHER    FCP  iSCSI     FCP   kB/s   iSCSI   kB/s
                                       in    out    read  write    read  write    age    hit  time  ty  util                            in    out      in    out
18%    713      0      0    1802     308   4102  139025 138664       0      0     1s    93%  100%  :s   17%     106    983      0   12370  67131       0      0
18%    653      0      0    2290     356   3024  175784 114858       0      0     0s    93%  100%  :s   17%     103   1534      0   30419 103879       0      0
14%    277      0      0    1117     264    835   96862  48373       0      0     0s    93%  100%  :s   16%     168    672      0   12616  68979       0      0
13%    465      0      0    1236     616   1505   56551     19       0      0     0s    94%  100%  :s   13%     150    621      0   10984  51964       0      0
13%    363      0      0    1184     359    724   47141      6       0      0     1     93%  100%  :s   14%     175    646      0   15597  41360       0      0
16%    394      0      0    1192     330   1622  150649  62399       0      0     0s    93%  100%  :s   21%     149    649      0   13094  89017       0      0
16%   1660      0      0    2609    1180   3836  101862     22       0      0     1     88%  100%  :s   15%     203    746      0   12464  58093       0      0
15%   2306      0      0    3503    1574  23707  144890      0       0      0     0s    93%  100%  :s   17%     442    755      0   11702  95250       0      0
14%   1118      0      0    2256     570  30514   97837  33885       0      0     1     95%  100%  :f   10%     612    526      0    9866  54222       0      0
14%   3636      0      0    4489    1649   7360   70514     66       0      0     1     92%  100%  :v    7%     238    615      0   10162  56678       0      0
13%   3540      0      0    4277    1615   2594   63757      0       0      0     1s    91%  100%  :v    6%     129    608      0   14768  48771       0      0
16%   2842      0      0    4097    1682  20595  137085     22       0      0     1     93%  100%  :v   14%     416    839      0   14408  78167       0      0
15%   2544      0      0    3760    1540  37961  125949      0       0      0     0s    94%  100%  :v   10%     692    524      0   10924 100674       0      0
26%   2493      0      0    4307     991   9312  275089 153829       0      0     0s    94%   90%  Zs   22%     329   1485      0   44023 126413       0      0
16%   1624      0      0    2577    1154   3959  179468  99585       0      0     0s    93%  100%  :s   20%     145    808      0   20926  89793       0      0
19%   2543      0      0    4807    2015  59604  258735  76443       0      0     0s    94%  100%  :s   17%    1042   1222      0   30911 147132       0      0
18%   3354      0      0    4264    1452   1771  189401  92019       0      0     0s    94%  100%  :s    7%      93    817      0   14723  84496       0      0
13%   3561      0      0    4435    1553   1027   99965  47137       0      0     0s    93%  100%  :s    6%     101    773      0   10691  82650       0      0
18%   2808      0      0    3998    1687   6156  174923    125       0      0     1     92%  100%  :s   14%     216    974      0   19335 117237       0      0
18%   4372      0      0    6370    2245  55867  242723  67036       0      0     0s    94%  100%  :s   10%    1019    979      0   19915 133940       0      0
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19501 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 3 of 21127
11363427    block ownership calculation     block 6400 of 21126
11363428     blocks used summary update     block 889 of 21127
 
 
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19501 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 5 of 21127
11363427    block ownership calculation     block 6500 of 21126
11363428     blocks used summary update     block 2096 of 21127
 
 
 
Volume $$$$$$$$$$$$$$$$$$$$$$$$$$:
Scan id                   Type of scan     progress
       6    active bitmap rearrangement     fbn 19502 of 21126 w/ max_chain_len 3
11362705     snap create summary update     block 4 of 21127 (fbn 211)
11363427    block ownership calculation     block 7100 of 21126
11363428     blocks used summary update     block 2799 of 21127 (fbn 3952)
 
 
 
 
This e-mail and its attachments are intended only for the individual or entity to whom it is addressed and may contain information that is confidential, privileged, inside information, or subject to other restrictions on use or disclosure. Any unauthorized use, dissemination or copying of this transmission or the information in it is prohibited and may be unlawful. If you have received this transmission in error, please notify the sender immediately by return e-mail, and permanently delete or destroy this e-mail, any attachments, and all copies (digital or paper). Unless expressly stated in this e-mail, nothing in this message should be construed as a digital or electronic signature. For additional important disclaimers and disclosures regarding KCG’s products and services, please click on the following link:

http://www.kcg.com/legal/global-disclosures



_______________________________________________
Toasters mailing list
[hidden email]
http://www.teaparty.net/mailman/listinfo/toasters