* re: backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? [not found] <B0AAEC04-DBAE-49AB-A549-B772D5F1B7F6@fordham.edu> @ 2017-05-11 20:42 ` Robert Kudyba [not found] ` <D5627D5A-065B-4C28-B152-7B0A587A0CBF-tzaSEmCkE7qVc3sceRu5cw@public.gmane.org> 0 siblings, 1 reply; 5+ messages in thread From: Robert Kudyba @ 2017-05-11 20:42 UTC (permalink / raw) To: linux-cifs-u79uwXL29TY76Z2rM5mHXA >> Could you provide a network trace of the isssue happening? You can add a >> new bug report on bugzilla.samba.org in the cifsVFS/kernel fs section >> and attach the trace there. > I submitted a bug. Seems to happen every night. Cron starts at 11:30 PM. Error happens around 1:25 AM. Here are some logs in context as well as a tcpdump—drobo-ds is the NAS backup device. I created a large (3GB) tcpdump during the backup but it’s way too big to upload. Could this be bufferbloat? > > May 11 01:22:23 ourserver kernel: CIFS VFS: Server droboh has not responded in 120 seconds. Reconnecting... > May 11 01:23:40 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds > May 11 01:23:40 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server > May 11 01:24:24 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds > May 11 01:24:24 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server > May 11 01:25:00 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds > May 11 01:25:00 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server > May 11 01:25:16 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds > May 11 01:25:16 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server > May 11 01:25:49 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds > May 11 01:25:49 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server > > reading from file capture_eth1.pcap, link-type EN10MB (Ethernet) > 01:29:10.445882 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 2359428476:2359428700, ack 4223248510, win 1444, options [nop,nop,TS val 1979978735 ecr 775533219], length 224: NFS request xid 2016398399 220 getattr fh 0,2/53 > 01:29:10.446331 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 1:173, ack 224, win 5204, options [nop,nop,TS val 775535659 ecr 1979978735], length 172: NFS reply xid 2016398399 reply ok 168 getattr NON 4 ids 0/1730480217 sz 1861894709 > 01:29:10.446378 IP ourserver.uuidgen > fileserver.nfs: Flags [.], ack 173, win 1444, options [nop,nop,TS val 1979978736 ecr 775535659], length 0 > 01:29:10.446466 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 224:568, ack 173, win 1444, options [nop,nop,TS val 1979978736 ecr 775535659], length 344: NFS request xid 2033175615 340 getattr fh 0,2/53 > 01:29:10.447034 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 173:537, ack 568, win 5204, options [nop,nop,TS val 775535660 ecr 1979978736], length 364: NFS reply xid 2033175615 reply ok 360 getattr NON 6 ids 0/1730480217 sz 1861894709 > 01:29:10.447346 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 568:836, ack 537, win 1444, options [nop,nop,TS val 1979978737 ecr 775535660], length 268: NFS request xid 2049952831 264 getattr fh 0,2/53 > 01:29:10.465786 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 537:805, ack 836, win 5204, options [nop,nop,TS val 775535679 ecr 1979978737], length 268: NFS reply xid 2049952831 reply ok 264 getattr NON 4 ids 0/1730480217 sz 1861894709 > 01:29:13.964676 IP drobo-ds > ourserver.42582: Flags [.], ack 3571070888, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 > 01:29:13.964780 IP drobo-ds > ourserver.42582: Flags [.], ack 2897, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 > 01:29:13.965029 IP drobo-ds > ourserver.42582: Flags [.], ack 5793, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 > 01:29:13.965155 IP drobo-ds > ourserver.42582: Flags [.], ack 8689, win 26508, options [nop,nop,TS val 616097295 ecr 1073740629], length 0 > 01:29:13.965176 IP ourserver.42582 > drobo-ds: Flags [.], seq 101361:115841, ack 0, win 321, options [nop,nop,TS val 1073740637 ecr 616097295], length 14480 SMB-over-TCP packet:(raw data or continuation?) > > 01:29:13.965397 IP drobo-ds > ourserver.42582: Flags [.], ack 11585, win 26421, options [nop,nop,TS val 616097295 ecr 1073740630], length 0 > 01:29:13.965418 IP ourserver.42582 > drobo-ds: Flags [.], seq 115841:118737, ack 0, win 321, options [nop,nop,TS val 1073740638 ecr 616097295], length 2896 SMB-over-TCP packet:(raw data or continuation?) > > 01:29:13.966364 IP drobo-ds > ourserver.42582: Flags [P.], seq 0:51, ack 18825, win 25986, options [nop,nop,TS val 616097295 ecr 1073740630], length 51 SMB PACKET: SMBwriteX (REPLY) > > 01:29:13.966386 IP drobo-ds > ourserver.42582: Flags [.], ack 21721, win 26508, options [nop,nop,TS val 616097295 ecr 1073740630], length 0 > 01:29:13.966416 IP ourserver.42582 > drobo-ds: Flags [.], seq 118737:125977, ack 51, win 321, options [nop,nop,TS val 1073740639 ecr 616097295], length 7240 SMB-over-TCP packet:(raw data or continuation?) > > 01:29:13.966658 IP drobo-ds > ourserver.42582: Flags [.], ack 24617, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 > 01:29:13.966783 IP drobo-ds > ourserver.42582: Flags [.], ack 27513, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 > 01:29:13.967054 IP drobo-ds > ourserver.42582: Flags [.], ack 30409, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 > 01:29:13.967072 IP ourserver.42582 > drobo-ds: Flags [P.], seq 125977:137561, ack 51, win 321, options [nop,nop,TS val 1073740639 ecr 616097295], length 11584 SMB-over-TCP packet:(raw data or continuation?) > > 01:29:13.967408 IP drobo-ds > ourserver.42582: Flags [.], ack 33305, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 > 01:29:13.968436 IP drobo-ds > ourserver.42582: Flags [.], ack 44889, win 26508, options [nop,nop,TS val 616097296 ecr 1073740632], length 0 > 01:29:13.968460 IP ourserver.42582 > drobo-ds: Flags [.], seq 140457:152041, ack 51, win 321, options [nop,nop,TS val 1073740641 ecr 616097296], length 11584 SMB-over-TCP packet:(raw data or continuation?) > > 01:29:13.968515 IP drobo-ds > ourserver.42582: Flags [.], ack 47785, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 > 01:29:13.968782 IP drobo-ds > ourserver.42582: Flags [.], ack 50681, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 > 01:29:13.969224 IP drobo-ds > ourserver.42582: Flags [.], ack 53577, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 > 01:29:13.969242 IP ourserver.42582 > drobo-ds: Flags [.], seq 152041:160729, ack 51, win 321, options [nop,nop,TS val 1073740642 ecr 616097296], length 8688 SMB-over-TCP packet:(raw data or continuation?) > > ^ permalink raw reply [flat|nested] 5+ messages in thread
[parent not found: <D5627D5A-065B-4C28-B152-7B0A587A0CBF-tzaSEmCkE7qVc3sceRu5cw@public.gmane.org>]
* Re: backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? [not found] ` <D5627D5A-065B-4C28-B152-7B0A587A0CBF-tzaSEmCkE7qVc3sceRu5cw@public.gmane.org> @ 2017-05-11 22:56 ` Richard Sharpe [not found] ` <CAFHi+KS6HtBGvqTJxNgMYvBaYnibryf==5x8FTJfGtjMJOSkBA@mail.gmail.com> 0 siblings, 1 reply; 5+ messages in thread From: Richard Sharpe @ 2017-05-11 22:56 UTC (permalink / raw) To: Robert Kudyba; +Cc: linux-cifs On Thu, May 11, 2017 at 1:42 PM, Robert Kudyba <rkudyba-tzaSEmCkE7qVc3sceRu5cw@public.gmane.org> wrote: >>> Could you provide a network trace of the isssue happening? You can add a >>> new bug report on bugzilla.samba.org in the cifsVFS/kernel fs section >>> and attach the trace there. > >> I submitted a bug. Seems to happen every night. Cron starts at 11:30 PM. Error happens around 1:25 AM. Here are some logs in context as well as a tcpdump—drobo-ds is the NAS backup device. I created a large (3GB) tcpdump during the backup but it’s way too big to upload. Could this be bufferbloat? This suggests that the Drobo is simply going off into the weeds somewhere. Do you have enough storage on it. They will insert write delays when storage is low, but I didn't think they would insert 120 seconds. Also, if you run the capture through tshark you can get a text listing of the requests that might allow you to find the location where the Drobo stops responding and then you can extract the 100-1000 packets around that point. tshark -r whatever-your-capture-is.pcap. >> May 11 01:22:23 ourserver kernel: CIFS VFS: Server droboh has not responded in 120 seconds. Reconnecting... >> May 11 01:23:40 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds >> May 11 01:23:40 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server >> May 11 01:24:24 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds >> May 11 01:24:24 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server >> May 11 01:25:00 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds >> May 11 01:25:00 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server >> May 11 01:25:16 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds >> May 11 01:25:16 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server >> May 11 01:25:49 ourserver kernel: CIFS VFS: sends on sock ffff9f2881408c80 stuck for 15 seconds >> May 11 01:25:49 ourserver kernel: CIFS VFS: Error -11 sending data on socket to server >> >> reading from file capture_eth1.pcap, link-type EN10MB (Ethernet) >> 01:29:10.445882 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 2359428476:2359428700, ack 4223248510, win 1444, options [nop,nop,TS val 1979978735 ecr 775533219], length 224: NFS request xid 2016398399 220 getattr fh 0,2/53 >> 01:29:10.446331 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 1:173, ack 224, win 5204, options [nop,nop,TS val 775535659 ecr 1979978735], length 172: NFS reply xid 2016398399 reply ok 168 getattr NON 4 ids 0/1730480217 sz 1861894709 >> 01:29:10.446378 IP ourserver.uuidgen > fileserver.nfs: Flags [.], ack 173, win 1444, options [nop,nop,TS val 1979978736 ecr 775535659], length 0 >> 01:29:10.446466 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 224:568, ack 173, win 1444, options [nop,nop,TS val 1979978736 ecr 775535659], length 344: NFS request xid 2033175615 340 getattr fh 0,2/53 >> 01:29:10.447034 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 173:537, ack 568, win 5204, options [nop,nop,TS val 775535660 ecr 1979978736], length 364: NFS reply xid 2033175615 reply ok 360 getattr NON 6 ids 0/1730480217 sz 1861894709 >> 01:29:10.447346 IP ourserver.uuidgen > fileserver.nfs: Flags [P.], seq 568:836, ack 537, win 1444, options [nop,nop,TS val 1979978737 ecr 775535660], length 268: NFS request xid 2049952831 264 getattr fh 0,2/53 >> 01:29:10.465786 IP fileserver.nfs > ourserver.uuidgen: Flags [P.], seq 537:805, ack 836, win 5204, options [nop,nop,TS val 775535679 ecr 1979978737], length 268: NFS reply xid 2049952831 reply ok 264 getattr NON 4 ids 0/1730480217 sz 1861894709 >> 01:29:13.964676 IP drobo-ds > ourserver.42582: Flags [.], ack 3571070888, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 >> 01:29:13.964780 IP drobo-ds > ourserver.42582: Flags [.], ack 2897, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 >> 01:29:13.965029 IP drobo-ds > ourserver.42582: Flags [.], ack 5793, win 26508, options [nop,nop,TS val 616097295 ecr 1073740628], length 0 >> 01:29:13.965155 IP drobo-ds > ourserver.42582: Flags [.], ack 8689, win 26508, options [nop,nop,TS val 616097295 ecr 1073740629], length 0 >> 01:29:13.965176 IP ourserver.42582 > drobo-ds: Flags [.], seq 101361:115841, ack 0, win 321, options [nop,nop,TS val 1073740637 ecr 616097295], length 14480 SMB-over-TCP packet:(raw data or continuation?) >> >> 01:29:13.965397 IP drobo-ds > ourserver.42582: Flags [.], ack 11585, win 26421, options [nop,nop,TS val 616097295 ecr 1073740630], length 0 >> 01:29:13.965418 IP ourserver.42582 > drobo-ds: Flags [.], seq 115841:118737, ack 0, win 321, options [nop,nop,TS val 1073740638 ecr 616097295], length 2896 SMB-over-TCP packet:(raw data or continuation?) >> >> 01:29:13.966364 IP drobo-ds > ourserver.42582: Flags [P.], seq 0:51, ack 18825, win 25986, options [nop,nop,TS val 616097295 ecr 1073740630], length 51 SMB PACKET: SMBwriteX (REPLY) >> >> 01:29:13.966386 IP drobo-ds > ourserver.42582: Flags [.], ack 21721, win 26508, options [nop,nop,TS val 616097295 ecr 1073740630], length 0 >> 01:29:13.966416 IP ourserver.42582 > drobo-ds: Flags [.], seq 118737:125977, ack 51, win 321, options [nop,nop,TS val 1073740639 ecr 616097295], length 7240 SMB-over-TCP packet:(raw data or continuation?) >> >> 01:29:13.966658 IP drobo-ds > ourserver.42582: Flags [.], ack 24617, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 >> 01:29:13.966783 IP drobo-ds > ourserver.42582: Flags [.], ack 27513, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 >> 01:29:13.967054 IP drobo-ds > ourserver.42582: Flags [.], ack 30409, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 >> 01:29:13.967072 IP ourserver.42582 > drobo-ds: Flags [P.], seq 125977:137561, ack 51, win 321, options [nop,nop,TS val 1073740639 ecr 616097295], length 11584 SMB-over-TCP packet:(raw data or continuation?) >> >> 01:29:13.967408 IP drobo-ds > ourserver.42582: Flags [.], ack 33305, win 26508, options [nop,nop,TS val 616097295 ecr 1073740631], length 0 >> 01:29:13.968436 IP drobo-ds > ourserver.42582: Flags [.], ack 44889, win 26508, options [nop,nop,TS val 616097296 ecr 1073740632], length 0 >> 01:29:13.968460 IP ourserver.42582 > drobo-ds: Flags [.], seq 140457:152041, ack 51, win 321, options [nop,nop,TS val 1073740641 ecr 616097296], length 11584 SMB-over-TCP packet:(raw data or continuation?) >> >> 01:29:13.968515 IP drobo-ds > ourserver.42582: Flags [.], ack 47785, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 >> 01:29:13.968782 IP drobo-ds > ourserver.42582: Flags [.], ack 50681, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 >> 01:29:13.969224 IP drobo-ds > ourserver.42582: Flags [.], ack 53577, win 26508, options [nop,nop,TS val 616097296 ecr 1073740634], length 0 >> 01:29:13.969242 IP ourserver.42582 > drobo-ds: Flags [.], seq 152041:160729, ack 51, win 321, options [nop,nop,TS val 1073740642 ecr 616097296], length 8688 SMB-over-TCP packet:(raw data or continuation?) >> >> > > -- > To unsubscribe from this list: send the line "unsubscribe linux-cifs" in > the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org > More majordomo info at http://vger.kernel.org/majordomo-info.html -- Regards, Richard Sharpe (何以解憂？唯有杜康。--曹操) ^ permalink raw reply [flat|nested] 5+ messages in thread
[parent not found: <CAFHi+KS6HtBGvqTJxNgMYvBaYnibryf==5x8FTJfGtjMJOSkBA@mail.gmail.com>]
[parent not found: <CAFHi+KRGNSvfgj7o+tK0RZZa9Nf2NQANUiygsUR5aokJH5NP7w@mail.gmail.com>]
[parent not found: <CAFHi+KSB348xPhYSf=x7FW9kmgU5iN-mDGvs2Fhyv=UYCMQckw@mail.gmail.com>]
[parent not found: <CAFHi+KRjK-pLxr+gNkE0jpsM1YfgE4s2Lw8Q4XTSTP-V0_Ds8A@mail.gmail.com>]
[parent not found: <CAFHi+KRjK-pLxr+gNkE0jpsM1YfgE4s2Lw8Q4XTSTP-V0_Ds8A-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org>]
* Fwd: backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? [not found] ` <CAFHi+KRjK-pLxr+gNkE0jpsM1YfgE4s2Lw8Q4XTSTP-V0_Ds8A-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org> @ 2017-05-12 2:37 ` Robert Kudyba [not found] ` <CAFHi+KQhXFrOVDb51fZCs1e5ik3RY+v91H5Sz1Z3YkgUpMPURw-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org> 0 siblings, 1 reply; 5+ messages in thread From: Robert Kudyba @ 2017-05-12 2:37 UTC (permalink / raw) To: linux-cifs Does this help? Here's the last few lines. Seems to be increasing in time? 424 0.101504413 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=817 Ack=1072969 Win=26508 Len=0 TSval=623636942 TSecr=2708013080 427 0.101741409 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=817 Ack=1075865 Win=26508 Len=0 TSval=623636942 TSecr=2708013081 432 0.102065108 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=817 Ack=1080209 Win=26334 Len=0 TSval=623636942 TSecr=2708013081 433 0.102072906 ourserver → drobo TCP 13098 [TCP segment of a reassembled PDU] 438 0.102829996 drobo → ourserver SMB 117 Write AndX Response, 65536 bytes 439 0.103240767 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1090345 Win=26508 Len=0 TSval=623636943 TSecr=2708013082 440 0.103251494 ourserver → drobo TCP 10202 [TCP segment of a reassembled PDU] 441 0.103259721 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1093241 Win=26508 Len=0 TSval=623636943 TSecr=2708013082 442 0.103475120 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1096137 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 443 0.103794874 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1099033 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 444 0.104305892 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1101929 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 445 0.104312236 ourserver → drobo TCP 11650 [TCP segment of a reassembled PDU] 446 0.104320705 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1104825 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 447 0.104568606 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1107721 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 448 0.104935339 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1110617 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 449 0.104945095 ourserver → drobo TCP 8754 [TCP segment of a reassembled PDU] 450 0.104953663 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1113513 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 451 0.105193542 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1116409 Win=26508 Len=0 TSval=623636943 TSecr=2708013083 452 0.105666892 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1119305 Win=26508 Len=0 TSval=623636943 TSecr=2708013084 453 0.105922535 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1122201 Win=26508 Len=0 TSval=623636943 TSecr=2708013084 454 0.105935375 ourserver → drobo TCP 11650 [TCP segment of a reassembled PDU] 455 0.105944869 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1125097 Win=26508 Len=0 TSval=623636943 TSecr=2708013085 456 0.106190594 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1127993 Win=26508 Len=0 TSval=623636943 TSecr=2708013085 458 0.106504814 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1130889 Win=26508 Len=0 TSval=623636943 TSecr=2708013085 459 0.106510176 ourserver → drobo TCP 7306 [TCP segment of a reassembled PDU] 460 0.106763808 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1133785 Win=26508 Len=0 TSval=623636943 TSecr=2708013085 461 0.107075671 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1136681 Win=26508 Len=0 TSval=623636943 TSecr=2708013086 462 0.107081982 ourserver → drobo TCP 7306 [TCP segment of a reassembled PDU] 463 0.107332634 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1139577 Win=26508 Len=0 TSval=623636943 TSecr=2708013086 464 0.107668225 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1142473 Win=26508 Len=0 TSval=623636943 TSecr=2708013086 465 0.107676435 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=868 Ack=1145369 Win=26421 Len=0 TSval=623636943 TSecr=2708013086 466 0.108678068 drobo → ourserver SMB 117 Write AndX Response, 65536 bytes 467 0.108694727 ourserver → drobo TCP 13098 [TCP segment of a reassembled PDU] 468 0.108703948 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1155505 Win=25812 Len=0 TSval=623636943 TSecr=2708013087 469 0.108951009 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1158401 Win=26508 Len=0 TSval=623636943 TSecr=2708013088 470 0.108961831 ourserver → drobo TCP 8754 [TCP segment of a reassembled PDU] 471 0.109218407 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1161297 Win=26508 Len=0 TSval=623636943 TSecr=2708013088 472 0.109231036 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1164193 Win=26508 Len=0 TSval=623636943 TSecr=2708013088 473 0.109662758 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1167089 Win=26508 Len=0 TSval=623636943 TSecr=2708013088 474 0.109918958 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1169985 Win=26508 Len=0 TSval=623636943 TSecr=2708013088 475 0.109932278 ourserver → drobo TCP 11650 [TCP segment of a reassembled PDU] 476 0.110190734 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1172881 Win=26508 Len=0 TSval=623636943 TSecr=2708013089 477 0.110200652 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1175777 Win=26508 Len=0 TSval=623636943 TSecr=2708013089 478 0.110661525 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1178673 Win=26508 Len=0 TSval=623636943 TSecr=2708013089 479 0.110670551 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1181569 Win=26508 Len=0 TSval=623636943 TSecr=2708013090 480 0.111313324 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1184465 Win=26508 Len=0 TSval=623636943 TSecr=2708013090 481 0.111325306 ourserver → drobo TCP 13098 [TCP segment of a reassembled PDU] 482 0.111336728 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1187361 Win=26508 Len=0 TSval=623636943 TSecr=2708013090 483 0.111579771 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1190257 Win=26508 Len=0 TSval=623636943 TSecr=2708013090 484 0.111918239 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1193153 Win=26508 Len=0 TSval=623636943 TSecr=2708013091 485 0.111924773 ourserver → drobo TCP 10202 [TCP segment of a reassembled PDU] 486 0.112172538 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1196049 Win=26508 Len=0 TSval=623636943 TSecr=2708013091 487 0.112178669 ourserver → drobo TCP 1514 [TCP segment of a reassembled PDU] 488 0.112186029 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1198945 Win=26508 Len=0 TSval=623636943 TSecr=2708013091 489 0.112430393 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1201841 Win=26508 Len=0 TSval=623636943 TSecr=2708013092 490 0.112934871 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1204737 Win=26508 Len=0 TSval=623636943 TSecr=2708013092 491 0.112946063 ourserver → drobo TCP 10202 [TCP segment of a reassembled PDU] 492 0.113132494 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1207633 Win=26508 Len=0 TSval=623636944 TSecr=2708013092 493 0.113256633 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=919 Ack=1211977 Win=26334 Len=0 TSval=623636944 TSecr=2708013092 494 0.114291076 drobo → ourserver SMB 117 Write AndX Response, 65536 bytes 495 0.114305898 ourserver → drobo TCP 13098 [TCP segment of a reassembled PDU] 496 0.114548027 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=970 Ack=1222113 Win=26508 Len=0 TSval=623636944 TSecr=2708013093 497 0.114554350 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=970 Ack=1225009 Win=26508 Len=0 TSval=623636944 TSecr=2708013093 498 0.114559411 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=970 Ack=1227905 Win=26508 Len=0 TSval=623636944 TSecr=2708013094 499 0.115071785 drobo → ourserver TCP 66 445 → 58706 [ACK] Seq=970 Ack=1230801 Win=26508 Len=0 TSval=623636944 TSecr=2708013094 500 0.115078479 ourserver → drobo TCP 13098 [TCP segment of a reassembled PDU] ^ permalink raw reply [flat|nested] 5+ messages in thread
[parent not found: <CAFHi+KQhXFrOVDb51fZCs1e5ik3RY+v91H5Sz1Z3YkgUpMPURw-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org>]
* Re: Fwd: backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? [not found] ` <CAFHi+KQhXFrOVDb51fZCs1e5ik3RY+v91H5Sz1Z3YkgUpMPURw-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org> @ 2017-05-12 11:49 ` Aurélien Aptel [not found] ` <mpsinl6cn2g.fsf-zpEvHKhluMwYitT5tn2FcQ@public.gmane.org> 0 siblings, 1 reply; 5+ messages in thread From: Aurélien Aptel @ 2017-05-12 11:49 UTC (permalink / raw) To: Robert Kudyba, linux-cifs Hi Robert, The capture you posted unfortunately does not contain anything of worth looking at I think. Only 2 SMB packets. % tshark -r capture.pcap -Y 'smb||smb2' 1130 15.032933 150.108.64.56 → 150.108.68.23 SMB 144 Trans2 Request, QUERY_PATH_INFO, Query File All Info, Path: 1131 15.034786 150.108.68.23 → 150.108.64.56 SMB 204 Trans2 Response, QUERY_PATH_INFO Given your kernel log message I would expect seeing the reconnecting happen. I would wrap your backup script like so to get the right capture: capfile="$(date -Ihours)" tcpdump -w "$capfile" port 445 & cappid=$! sleep 2 .....<your script>.... sleep 2 kill -6 $cappid -- Aurélien Aptel / SUSE Labs Samba Team GPG: 1839 CB5F 9F5B FB9B AA97 8C99 03C8 A49B 521B D5D3 SUSE Linux GmbH, Maxfeldstraße 5, 90409 Nürnberg, Germany GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 (AG Nürnberg) ^ permalink raw reply [flat|nested] 5+ messages in thread
[parent not found: <mpsinl6cn2g.fsf-zpEvHKhluMwYitT5tn2FcQ@public.gmane.org>]
* Re: Fwd: backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? [not found] ` <mpsinl6cn2g.fsf-zpEvHKhluMwYitT5tn2FcQ@public.gmane.org> @ 2017-05-12 13:45 ` Robert Kudyba 0 siblings, 0 replies; 5+ messages in thread From: Robert Kudyba @ 2017-05-12 13:45 UTC (permalink / raw) To: Aurélien Aptel; +Cc: linux-cifs > Given your kernel log message I would expect seeing the reconnecting happen. I scheduled a tshark -c over night and was able to get it to run within minutes of the reconnect attempts.It seems pretty consistent, about 2 hours after the start of the cron the Error -11's start to happen. Last night it also happened about 30 minutes into the job: May 11 23:47:51 localworkstation kernel: CIFS VFS: Server drobo-rh has not responded in 120 seconds. Reconnecting... May 11 23:49:59 localworkstation kernel: CIFS VFS: Server drobo-rh has not responded in 120 seconds. Reconnecting... May 11 23:52:57 localworkstation kernel: CIFS VFS: Server drobo-rh has not responded in 120 seconds. Reconnecting... May 12 01:19:44 localworkstation cupsd: REQUEST localhost - - "POST / HTTP/1.1" 200 181 Renew-Subscription successful-ok May 12 01:21:20 localworkstation kernel: CIFS VFS: sends on sock ffff9f2817bede00 stuck for 15 seconds May 12 01:21:20 localworkstation kernel: CIFS VFS: Error -11 sending data on socket to server Here's the tshark -r tshark.pcap -Y 'smb||smb2' results from 2 files: 593 0.273687063 drobo → localserver SMB 117 [TCP ACKed unseen segment] Write AndX Response, 65536 bytes 666 0.282264835 drobo → localserver SMB 117 Write AndX Response, 65536 bytes 8 0.136979937 drobo → localserver SMB 117 [TCP ACKed unseen segment] [TCP Previous segment not captured] Write AndX Response, 65536 bytes 36 0.142752037 drobo → localserver SMB 117 Write AndX Response, 65536 bytes 63 0.149017707 drobo → localserver SMB 117 Write AndX Response, 65536 bytes > I would wrap your backup script like so to get the right capture: > > capfile="$(date -Ihours)" > tcpdump -w "$capfile" port 445 & > cappid=$! > sleep 2 > .....<your script>.... > sleep 2 > kill -6 $cappid OK just did that and started running the backup manually so far I've seen variations/multiples of these (cut for easier reading): 38735 18.521926 localserver → drobo SMB 10202 Write AndX Request, FID: 0x1fca, 65536 bytes at offset 87949312[TCP segment of a reassembled PDU] 38760 18.527189 localserver → drobo SMB 7306 Write AndX Request, FID: 0x1fca, 65536 bytes at offset 88014848[TCP segment of a reassembled PDU] 38771 18.529817 drobo → localserver SMB 117 Write AndX Response, FID: 0x1fca, 65536 bytes 44079 19.615349 drobo → localserver SMB 117 [TCP ACKed unseen segment] Write AndX Response, 65536 bytes 44102 19.626642 drobo → localserver SMB 117 [TCP ACKed unseen segment] Write AndX Response, 65536 bytes ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2017-05-12 13:45 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <B0AAEC04-DBAE-49AB-A549-B772D5F1B7F6@fordham.edu>
2017-05-11 20:42 ` backing up to a Drobo CIFS VFS: Error -11 sending data on socket to server, Bufferbloat? Robert Kudyba
[not found] ` <D5627D5A-065B-4C28-B152-7B0A587A0CBF-tzaSEmCkE7qVc3sceRu5cw@public.gmane.org>
2017-05-11 22:56 ` Richard Sharpe
[not found] ` <CAFHi+KS6HtBGvqTJxNgMYvBaYnibryf==5x8FTJfGtjMJOSkBA@mail.gmail.com>
[not found] ` <CAFHi+KRGNSvfgj7o+tK0RZZa9Nf2NQANUiygsUR5aokJH5NP7w@mail.gmail.com>
[not found] ` <CAFHi+KSB348xPhYSf=x7FW9kmgU5iN-mDGvs2Fhyv=UYCMQckw@mail.gmail.com>
[not found] ` <CAFHi+KRjK-pLxr+gNkE0jpsM1YfgE4s2Lw8Q4XTSTP-V0_Ds8A@mail.gmail.com>
[not found] ` <CAFHi+KRjK-pLxr+gNkE0jpsM1YfgE4s2Lw8Q4XTSTP-V0_Ds8A-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org>
2017-05-12 2:37 ` Fwd: " Robert Kudyba
[not found] ` <CAFHi+KQhXFrOVDb51fZCs1e5ik3RY+v91H5Sz1Z3YkgUpMPURw-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org>
2017-05-12 11:49 ` Aurélien Aptel
[not found] ` <mpsinl6cn2g.fsf-zpEvHKhluMwYitT5tn2FcQ@public.gmane.org>
2017-05-12 13:45 ` Robert Kudyba
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.