toasters April 2013

toasters@lists.teaparty.net

49 participants
25 discussions

NVRAM weirdness
by Peta Thames 13 Apr '13

13 Apr '13

Hi all, Has anyone seen this pattern in a sysstat before? TOASTERa> sysstat -u 1 CPU Total Net kB/s Disk kB/s Tape kB/s Cache Cache CP CP Disk ops/s in out read write read write age hit time ty util 29% 36942 1 0 264 0 0 0 7s 91% 100% # 100% 29% 36896 1 0 1616 0 0 0 7s 90% 100% # 100% 28% 36658 1 0 32 24 0 0 7s 100% 100% # 100% 28% 36625 1 0 108 0 0 0 7s 97% 100% # 100% 27% 36318 1 0 136 8 0 0 7s 100% 100% # 100% 28% 36391 1 0 364 144 0 0 7s 97% 100% # 100% 25% 30387 1 0 88 0 0 0 7s 98% 100% # 100% 21% 24450 1 0 8 0 0 0 7s 100% 100% # 100% 20% 22042 1 0 24 672 0 0 7s 100% 100% # 100% 18% 19781 1 0 284 8 0 0 7s 69% 100% # 100% 18% 19636 1 0 0 0 0 0 7s 100% 100% # 100% 16% 18066 1 0 24 24 0 0 7s 100% 100% # 100% 15% 16999 1 0 56 0 0 0 7s 56% 100% # 100% 15% 16622 1 0 11040 6496 0 0 7s 46% 100% # 1824% 14% 15947 1 0 24 32 0 0 7s 100% 100% # 100% 14% 15448 0 0 0 0 0 0 7s 100% 100% # 100% 14% 15902 0 0 3304 4532 0 0 7s 88% 100% # 100% 14% 15800 0 0 32 24 0 0 7s 100% 100% # 100% 15% 16651 0 0 0 0 0 0 7s 100% 100% # 100% CPU Total Net kB/s Disk kB/s Tape kB/s Cache Cache CP CP Disk ops/s in out read write read write age hit time ty util 14% 15778 0 0 1520 2932 0 0 7s 100% 100% # 100% 13% 14311 0 1 28 24 0 0 7s 100% 100% # 100% 12% 12153 0 0 0 0 0 0 7s 100% 100% # 100% 12% 11993 0 0 8 0 0 0 7s 100% 100% # 100% 12% 12134 0 0 7368 5996 0 0 7s 18% 100% # 100% 13% 11981 0 0 20356 14956 0 0 7s 100% 100% # 100% 12% 11978 0 0 0 0 0 0 7s 100% 100% # 100% 11% 11617 0 0 24 24 0 0 7s 100% 100% # 100% 12% 11708 0 0 8 0 0 0 7s 100% 100% # 100% 11% 11630 0 0 11936 17872 0 0 7s 100% 100% # 100% 11% 11639 0 0 24 32 0 0 7s 100% 100% # 100% 12% 11791 0 0 12 0 0 0 7s 87% 100% # 100% 22% 11874 0 0 64452 92188 0 0 7s 100% 100% # 100% 12% 12015 0 0 32 24 0 0 7s 100% 100% # 100% 12% 11954 0 0 556 0 0 0 7s 85% 100% # 100% 12% 11899 0 0 0 8 0 0 7s 100% 100% # 100% 13% 13408 0 0 23816 35600 0 0 7s 91% 100% # 100% 13% 14610 0 0 0 0 0 0 7s 100% 100% # 100% 14% 15355 0 0 1248 0 0 0 7s 72% 100% # 100% 14% 15584 0 0 18652 15224 0 0 7s 98% 100% # 100% CPU Total Net kB/s Disk kB/s Tape kB/s Cache Cache CP CP Disk ops/s in out read write read write age hit time ty util 14% 15397 0 0 0 8 0 0 7s 100% 100% # 100% 15% 15859 0 1 0 0 0 0 7s 100% 100% # 100% 14% 15557 0 0 4944 4568 0 0 7s 100% 100% # 100% 14% 15559 0 0 8 0 0 0 7s 100% 100% # 100% 14% 15603 0 0 0 0 0 0 7s 100% 100% # 100% 14% 15507 0 0 3652 4724 0 0 7s 100% 100% # 100% 14% 15593 0 0 20 0 0 0 7s 75% 100% # 100% 12% 12571 0 0 268 0 0 0 7s 100% 100% # 100% 10% 9962 0 0 92 2072 0 0 7s 96% 100% # 100% 9% 8521 0 0 0 0 0 0 7s 100% 100% # 100% 8% 7680 0 0 4 8 0 0 7s 100% 100% # 100% 8% 7459 0 0 24 24 0 0 7s 100% 100% # 100% 8% 7050 0 0 2580 1600 0 0 7s 100% 100% # 100% 8% 6961 0 0 8 0 0 0 7s 100% 100% # 100% 8% 6954 0 0 24 24 0 0 7s 100% 100% # 100% 7% 6936 0 0 584 2400 0 0 7s 100% 100% # 100% 8% 7043 0 0 248 0 0 0 7s 0% 100% # 100% 7% 6946 0 0 24 24 0 0 7s 100% 100% # 100% 8% 7320 0 0 1860 7252 0 0 7s 100% 100% # 100% 55% 19882 2 2 89920 29733 0 0 1 86% 99% B 45% CPU Total Net kB/s Disk kB/s Tape kB/s Cache Cache CP CP Disk ops/s in out read write read write age hit time ty util 88% 17409 31 187 267319 196942 0 0 6s 83% 100% : 89% 87% 16064 11 249 304646 192912 0 0 1 78% 100% : 85% 85% 6274 70 86 322234 233245 0 0 1 81% 100% # 87% 85% 12486 18 340 236474 102383 0 0 3s 82% 100% B 73% 98% 13842 3 29 247937 255188 0 0 2s 85% 100% : 80% 99% 17878 1 1 348355 223367 0 0 3s 84% 100% # 86% 99% 4117 1 1 359628 269212 0 0 3s 78% 100% # 92% 83% 12622 10 31 252272 170064 0 0 2s 83% 100% B 73% 94% 19321 4 10 248864 249292 0 0 2s 88% 100% : 96% 99% 15893 0 0 318375 261482 0 0 2s 85% 100% : 89% 88% 13326 34 76 284960 194032 0 0 2s 82% 100% B 90% 86% 11106 73 104 267760 231524 0 0 2s 81% 100% : 100% 72% 11160 0 0 206927 128869 0 0 3s 75% 100% : 100% 63% 11304 0 0 220736 25276 0 0 3s 67% 100% : 100% 68% 11216 0 0 193324 15184 0 0 3s 66% 100% : 100% 65% 11343 0 0 175120 12588 0 0 3s 60% 100% : 100% 52% 7384 0 0 205780 104564 0 0 3s 61% 100% # 100% 83% 7205 0 0 261108 178256 0 0 3s 74% 100% B 90% 75% 11256 0 0 225164 96332 0 0 3s 76% 100% : 93% 99% 6279 0 0 296056 251191 0 0 2s 87% 100% : 90% CPU Total Net kB/s Disk kB/s Tape kB/s Cache Cache CP CP Disk ops/s in out read write read write age hit time ty util 65% 8616 0 0 220068 165749 0 0 2s 76% 73% : 71% 89% 5443 0 1 338684 239932 0 0 3s 80% 94% F 87% 95% 6726 0 0 379242 240750 0 0 3s 79% 100% : 91% 83% 8721 1 0 342940 113394 0 0 2s 82% 61% : 89% 77% 11971 1 0 314356 24 0 0 2s 85% 0% - 92% ... and back to normal. Looking in Perf Advisor, it was during an extremely short, sharp latency spike that impacted every volume on every aggregate at exact the same time. It was the fourth of four spikes that had happened a few minutes apart during the previous 20 mins. It looks like the NVRAM flush got stuck somehow but I have no idea what would cause that. We're running ONTAP 8.0.2 7-mode on a very busy FAS3170. Thanks, Peta

10 20

8.2RC1
by Fletcher Cocquyt 12 Apr '13

12 Apr '13

Just noticed 8.2RC1 is available for download - anyone testing it out yet? From the release notes, it sounds like they are changing the licensing scheme The notes also say to use upgrade advisor, yet ironically UA does not have 8.2 as available as an option. Looking to get the bug fixes for issues in 8.1 thanks

3 2

Fwd: > fcp start ... shows logins from hosts I don't have zoned
by Peter Kain 10 Apr '13

10 Apr '13

Thank's for the replies. Andrey, I see from "switchshow" on my Brocade 48000 that it is the SwitchID (Switch embedded port D_ID) and it's the Brocade Switch logging into the Filer I'm seeing. Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1a' from '21:fd:00:05:1e:36:3e:d2', address 0xfffc06. SW48000_A_5_6:admin> switchshow switchName: SW48000_A_5_6 switchType: 42.2 switchState: Online switchMode: Native switchRole: Principal switchDomain: 6 switchId: fffc06 switchWwn: 10:00:00:05:1e:36:3e:d2 Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1b' from '21:fd:00:05:1e:36:3d:96', address 0xfffc07. SW48000_B_7_8:admin> switchshow switchName: SW48000_B_7_8 switchType: 42.2 switchState: Online switchMode: Native switchRole: Principal switchDomain: 7 switchId: fffc07 switchWwn: 10:00:00:05:1e:36:3d:96 Pete On Tue, Apr 9, 2013 at 10:59 PM, Borzenkov, Andrey < andrey.borzenkov(a)ts.fujitsu.com> wrote: > 0xfffcXX is Brocade switch embedded port DID (XX is switch domain number). > 2x:xx:00:05:1e:xx:xx:xx is Brocade switch port WWN. Switch by default > actively probes attached devices to obtain name server information. It is > using above DID and PWWN 21:fd:xx:xx:xx:xx:xx:xx (I did not find this PWWN > to be explicitly documented though).**** > > ** ** > > Andrey **** > > ** ** > > ** ** > > *From:* toasters-bounces(a)teaparty.net [mailto: > toasters-bounces(a)teaparty.net] *On Behalf Of *Peter Kain > *Sent:* Tuesday, April 09, 2013 10:37 PM > > *To:* Toasters(a)teaparty.net > *Subject:* > fcp start ... shows logins from hosts I don't have zoned**** > > ** ** > > I'm setting up a new FAS2240 with a Dual FC card. > > - both ports are target adapters > > - each port is cabled to a separate brocade switch **** > > - a Solaris server with 2 fiber cards are cabled, one to each switch > > Basically there are two separate paths to the Filer from the server > through two Brocade switches. **** > > Where I'm confused is when I start Fiber channel services on the filer, > the adapters come online, the links come up, but then there are two logins > for each adapter. One of the logins on each adapter are from my server, > networker. **** > > Can anyone tell me what the second login on each adapter is from. I'm > fairly certain it's not an outside system. **** > > > fas2240> fcp start > Tue Apr 9 11:07:40 PDT [fas2240:scsitarget.ispfct.onlining:notice]: > Onlining Fibre Channel target adapter 1a. > Tue Apr 9 11:07:40 PDT [fas2240:scsitarget.ispfct.onlining:notice]: > Onlining Fibre Channel target adapter 1b. > > Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.linkUp:notice]: Link up > on Fibre Channel target adapter 1b. > Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.linkUp:notice]: Link up > on Fibre Channel target adapter 1a. > > Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: > FCP login on Fibre Channel adapter '1b' from '21:fd:00:05:1e:36:3d:96', > address 0xfffc07. <-- don't know what these are > > Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: > FCP login on Fibre Channel adapter '1a' from '21:fd:00:05:1e:36:3e:d2', > address 0xfffc06. <-- don't know what these are > > Tue Apr 9 11:07:44 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: > FCP login on Fibre Channel adapter '1b' from '21:00:00:e0:8b:83:3a:65', > address 0x70400. <-- networker > > Tue Apr 9 11:07:44 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: > FCP login on Fibre Channel adapter '1a' from '21:00:00:e0:8b:83:eb:67', > address 0x60400. <-- networker > > > fas2240> fcp show initiator > Initiators connected on adapter 1a: > Portname Group > -------- ----- > 21:00:00:e0:8b:83:eb:67 networker > > Initiators connected on adapter 1b: > Portname Group > -------- ----- > 21:00:00:e0:8b:83:3a:65 networker > "fc_start.htm" 65 lines, 2097 characters**** > > > > **** > > > -- > Pete Kain > 310-506-4475 **** > -- Pete Kain 310-506-4475 -- Pete Kain 310-506-4475

1 0

> fcp start ... shows logins from hosts I don't have zoned
by Peter Kain 10 Apr '13

10 Apr '13

I'm setting up a new FAS2240 with a Dual FC card. - both ports are target adapters - each port is cabled to a separate brocade switch - a Solaris server with 2 fiber cards are cabled, one to each switch Basically there are two separate paths to the Filer from the server through two Brocade switches. Where I'm confused is when I start Fiber channel services on the filer, the adapters come online, the links come up, but then there are two logins for each adapter. One of the logins on each adapter are from my server, networker. Can anyone tell me what the second login on each adapter is from. I'm fairly certain it's not an outside system. fas2240> fcp start Tue Apr 9 11:07:40 PDT [fas2240:scsitarget.ispfct.onlining:notice]: Onlining Fibre Channel target adapter 1a. Tue Apr 9 11:07:40 PDT [fas2240:scsitarget.ispfct.onlining:notice]: Onlining Fibre Channel target adapter 1b. Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.linkUp:notice]: Link up on Fibre Channel target adapter 1b. Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.linkUp:notice]: Link up on Fibre Channel target adapter 1a. Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1b' from '21:fd:00:05:1e:36:3d:96', address 0xfffc07. <-- don't know what these are Tue Apr 9 11:07:43 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1a' from '21:fd:00:05:1e:36:3e:d2', address 0xfffc06. <-- don't know what these are Tue Apr 9 11:07:44 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1b' from '21:00:00:e0:8b:83:3a:65', address 0x70400. <-- networker Tue Apr 9 11:07:44 PDT [fas2240:scsitarget.ispfct.portLogin:notice]: FCP login on Fibre Channel adapter '1a' from '21:00:00:e0:8b:83:eb:67', address 0x60400. <-- networker fas2240> fcp show initiator Initiators connected on adapter 1a: Portname Group -------- ----- 21:00:00:e0:8b:83:eb:67 networker Initiators connected on adapter 1b: Portname Group -------- ----- 21:00:00:e0:8b:83:3a:65 networker "fc_start.htm" 65 lines, 2097 characters -- Pete Kain 310-506-4475

3 2

Aggregate Disk Busy 100% with volume IOPS low
by Fletcher Cocquyt 01 Apr '13

01 Apr '13

3270 cluster, OnTAP 8.1-7mode We are investigating a SATA aggregate showing repeated 5am disk 100% busy spikes without its volumes showing any corresponding IOPS spike as reported by Netapp Management Console (NMC). The 5am disk busy spikes correlate with very high latency on volumes on a different SAS aggregate. These volumes host VMs which then timeout, some needing reboots. Today when I heard from Netapp support after reviewing my perfstat the engineer reported this is expected since NVRAM buffers are shared btw aggregates. But when I dig further into the NMC stats I see the SATA aggregate disk busy actually corresponds to a DROP in IOPS on the 3 volumes hosted on the SATA aggregate - almost like some internal aggregate operations are starving out the external volume ops. I checked the snapshots (vol and aggr), snap mirror, dedup and none of the usual suspects were running. When I look at the NMC throughput graphs and switch on the legend - it shows a 5am READ blocks/sec spike corresponding perfectly to the disk busy. Where are these AGGR level READ operations coming from that are missing from the constituent volume IOPS, and in fact seem to be starving out volume level IO? I don't see much in the messages log, but will check the rest of the logs for internal type OPS thanks for any insight

13 24

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

2001

2000

1999

1998

1997

toasters April 2013