TCP hang with 2.2.14 <-> 2.2.15pre5

[Stephen Rothwell <sfr@xxxxxxxxxxxxx>]

Hi all,

In diagnosing a report of a bug in rsync, we have discovered what
looks like a bug in the 2.2 TCP stack.  After transfering some
amount of data (usually 30MB or more) the connection hangs.

Below I have included the ends of tcpdumps from both ends.  The two
machines are called elm (running 2.2.15pre5 and doing most of the
transmitting) and owl (running 2.2.14).

Also elm gets a reasonable number (~10%) transmit errors.

We tried turning off SACK on the 2.2.14 machine.  This just seemed
to make it fail quicker (though this may not be so).

The first dump was collected on elm, the second on owl.

I have both complete dumps (from tcpdump -w) if you need them.

Cheers,
Stephen
-- 
Stephen Rothwell, Open Source Project Engineer, Linuxcare, Inc.
+61-2-62628990 tel, +61-2-62628991 fax 
sfr@xxxxxxxxxxxxx, http://www.linuxcare.com/ 
Linuxcare. Support for the revolution.

16:21:43.390093 elm.1216 > owl.rsync: P 31342678:31344126(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390104 elm.1216 > owl.rsync: P 31344126:31345574(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390114 elm.1216 > owl.rsync: P 31345574:31347022(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390124 elm.1216 > owl.rsync: P 31347022:31348470(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390132 elm.1216 > owl.rsync: P 31348470:31349918(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390843 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.390944 elm.1216 > owl.rsync: P 31349918:31351366(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390954 elm.1216 > owl.rsync: P 31351366:31352814(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390964 elm.1216 > owl.rsync: P 31352814:31354262(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390972 elm.1216 > owl.rsync: P 31354262:31355710(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.390980 elm.1216 > owl.rsync: P 31355710:31357158(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.391759 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.391763 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.391766 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.391837 elm.1216 > owl.rsync: P 31348470:31349918(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.391780 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.391815 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.391864 elm.1216 > owl.rsync: P 31357158:31358606(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.392252 owl.rsync > elm.1216: . ack 31357158 win 24616 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.392286 elm.1216 > owl.rsync: P 31358606:31360054(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.392296 elm.1216 > owl.rsync: P 31360054:31361502(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.392702 owl.rsync > elm.1216: . ack 31360054 win 23168 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.392730 elm.1216 > owl.rsync: P 31361502:31362950(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.392739 elm.1216 > owl.rsync: P 31362950:31364398(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.392750 elm.1216 > owl.rsync: P 31364398:31365846(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.393367 owl.rsync > elm.1216: . ack 31362950 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.393407 elm.1216 > owl.rsync: P 31365846:31367294(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.393417 elm.1216 > owl.rsync: P 31367294:31368742(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.393379 owl.rsync > elm.1216: . ack 31365846 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.393441 elm.1216 > owl.rsync: P 31368742:31370190(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.393451 elm.1216 > owl.rsync: P 31370190:31371638(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394073 owl.rsync > elm.1216: . ack 31368742 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.394108 elm.1216 > owl.rsync: P 31371638:31373086(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394119 elm.1216 > owl.rsync: P 31373086:31374534(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394148 owl.rsync > elm.1216: . ack 31371638 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.394176 elm.1216 > owl.rsync: P 31374534:31375982(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394186 elm.1216 > owl.rsync: P 31375982:31377430(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394195 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394853 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.394884 elm.1216 > owl.rsync: P 31378878:31380326(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394894 elm.1216 > owl.rsync: P 31380326:31381774(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394903 elm.1216 > owl.rsync: P 31381774:31383222(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.394913 elm.1216 > owl.rsync: P 31383222:31384670(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:21:43.395436 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.395491 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:21:43.566543 owl.rsync > elm.1216: P 76839:78287(1448) ack 31377430 win 
31856 <nop,nop,timestamp 528756057 2055367> (DF)
16:21:43.566608 elm.1216 > owl.rsync: . ack 78287 win 1448 <nop,nop,timestamp 
2055384 528756057> (DF)
16:21:43.566949 owl.rsync > elm.1216: . 78287:79735(1448) ack 31377430 win 
31856 <nop,nop,timestamp 528756057 2055367> (DF)
16:21:43.587451 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055387 528756057> (DF)
16:21:43.588103 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
28960 <nop,nop,timestamp 528756059 2055387> (DF)
16:21:43.588136 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055387 528756059> (DF)
16:21:43.786560 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756079 2055387> (DF)
16:21:43.786598 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055406 528756079> (DF)
16:21:43.987447 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055427 528756079> (DF)
16:21:43.987798 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756099 2055387> (DF)
16:21:43.987818 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055427 528756079> (DF)
16:21:44.186492 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756119 2055387> (DF)
16:21:44.186529 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055446 528756119> (DF)
16:21:44.787469 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055507 528756119> (DF)
16:21:44.787825 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756179 2055387> (DF)
16:21:44.787860 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055507 528756119> (DF)
16:21:44.986440 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756199 2055387> (DF)
16:21:44.986473 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055526 528756199> (DF)
16:21:46.387470 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055667 528756199> (DF)
16:21:46.387893 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756339 2055387> (DF)
16:21:46.387929 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055667 528756199> (DF)
16:21:46.586341 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756359 2055387> (DF)
16:21:46.586375 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055686 528756359> (DF)
16:21:49.587480 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055987 528756359> (DF)
16:21:49.587803 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756659 2055387> (DF)
16:21:49.587839 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055987 528756359> (DF)
16:21:49.786129 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756679 2055387> (DF)
16:21:49.786165 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056006 528756679> (DF)
16:21:55.987474 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2056627 528756679> (DF)
16:21:55.987864 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528757299 2055387> (DF)
16:21:55.987902 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056627 528756679> (DF)
16:21:56.185739 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528757319 2055387> (DF)
16:21:56.185810 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056646 528757319> (DF)
16:22:08.787452 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2057907 528757319> (DF)
16:22:08.787805 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528758579 2055387> (DF)
16:22:08.787833 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2057907 528757319> (DF)
16:22:08.984888 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528758599 2055387> (DF)
16:22:08.984922 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2057926 528758599> (DF)
16:22:34.387464 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2060467 528758599> (DF)
16:22:34.387756 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528761139 2055387> (DF)
16:22:34.387783 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2060467 528758599> (DF)
16:22:34.583229 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528761159 2055387> (DF)
16:22:34.583265 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2060486 528761159> (DF)
16:23:25.587464 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2065587 528761159> (DF)
16:23:25.587819 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528766259 2055387> (DF)
16:23:25.587843 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2065587 528761159> (DF)
16:23:25.779959 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528766279 2055387> (DF)
16:23:25.779993 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2065606 528766279> (DF)
16:25:07.987473 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2075827 528766279> (DF)
16:25:07.987870 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528776500 2055387> (DF)
16:25:07.987906 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2075827 528766279> (DF)
16:25:08.173267 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528776519 2055387> (DF)
16:25:08.173305 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2075845 528776519> (DF)
16:27:07.987482 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2087827 528776519> (DF)
16:27:07.987829 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528788501 2055387> (DF)
16:27:07.987865 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2087827 528776519> (DF)
16:27:08.165481 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528788519 2055387> (DF)
16:27:08.165518 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2087844 528788519> (DF)
16:29:07.987484 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2099827 528788519> (DF)
16:29:07.987827 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528800502 2055387> (DF)
16:29:07.987863 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2099827 528788519> (DF)
16:29:08.157687 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528800519 2055387> (DF)
16:29:08.157723 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2099844 528800519> (DF)
16:31:07.987495 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2111827 528800519> (DF)
16:31:07.987909 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528812502 2055387> (DF)
16:31:07.987952 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2111827 528800519> (DF)
16:31:08.149903 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528812519 2055387> (DF)
16:31:08.149958 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2111843 528812519> (DF)
16:33:07.987479 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2123827 528812519> (DF)
16:33:07.987844 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528824503 2055387> (DF)
16:33:07.987880 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2123827 528812519> (DF)
16:33:08.142121 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528824519 2055387> (DF)
16:33:08.142157 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2123842 528824519> (DF)
16:35:07.987478 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2135827 528824519> (DF)
16:35:07.987844 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528836504 2055387> (DF)
16:35:07.987879 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2135827 528824519> (DF)
16:35:08.134331 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528836519 2055387> (DF)
16:35:08.134366 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2135841 528836519> (DF)
16:37:07.987475 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2147827 528836519> (DF)
16:37:07.987900 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528848505 2055387> (DF)
16:37:07.987946 elm.1216 > owl.rsync: R 2680405324:2680405324(0) win 0
16:37:07.989904 elm.1216 > owl.rsync: R 31436798:31436798(0) ack 79735 win 
31856 <nop,nop,timestamp 2147827 528836519> (DF)

16:24:52.341380 elm.1216 > owl.rsync: P 31342678:31344126(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.341504 elm.1216 > owl.rsync: P 31344126:31345574(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.341536 owl.rsync > elm.1216: . ack 31345574 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.341626 elm.1216 > owl.rsync: P 31345574:31347022(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.341777 elm.1216 > owl.rsync: P 31347022:31348470(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.341810 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.342233 elm.1216 > owl.rsync: P 31349918:31351366(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.342279 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.342355 elm.1216 > owl.rsync: P 31351366:31352814(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.342390 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.342489 elm.1216 > owl.rsync: P 31352814:31354262(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.342523 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.342621 elm.1216 > owl.rsync: P 31354262:31355710(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.342654 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.342752 elm.1216 > owl.rsync: P 31355710:31357158(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.342784 owl.rsync > elm.1216: . ack 31348470 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.343124 elm.1216 > owl.rsync: P 31348470:31349918(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.343164 owl.rsync > elm.1216: . ack 31357158 win 24616 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.343247 elm.1216 > owl.rsync: P 31357158:31358606(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.343579 elm.1216 > owl.rsync: P 31358606:31360054(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.343638 owl.rsync > elm.1216: . ack 31360054 win 23168 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.343697 elm.1216 > owl.rsync: P 31360054:31361502(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344028 elm.1216 > owl.rsync: P 31361502:31362950(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344142 elm.1216 > owl.rsync: P 31362950:31364398(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344264 elm.1216 > owl.rsync: P 31364398:31365846(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344334 owl.rsync > elm.1216: . ack 31362950 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.344348 owl.rsync > elm.1216: . ack 31365846 win 30408 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.344703 elm.1216 > owl.rsync: P 31365846:31367294(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344819 elm.1216 > owl.rsync: P 31367294:31368742(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.344856 owl.rsync > elm.1216: . ack 31368742 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.344941 elm.1216 > owl.rsync: P 31368742:31370190(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345068 elm.1216 > owl.rsync: P 31370190:31371638(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345100 owl.rsync > elm.1216: . ack 31371638 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.345397 elm.1216 > owl.rsync: P 31371638:31373086(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345519 elm.1216 > owl.rsync: P 31373086:31374534(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345553 owl.rsync > elm.1216: . ack 31374534 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.345642 elm.1216 > owl.rsync: P 31374534:31375982(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345792 elm.1216 > owl.rsync: P 31375982:31377430(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.345822 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.346174 elm.1216 > owl.rsync: P 31378878:31380326(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.346218 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.346295 elm.1216 > owl.rsync: P 31380326:31381774(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.346328 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.346430 elm.1216 > owl.rsync: P 31381774:31383222(1448) ack 76839 win 
1448 <nop,nop,timestamp 2055367 528755997> (DF)
16:24:52.346461 owl.rsync > elm.1216: . ack 31377430 win 31856 
<nop,nop,timestamp 528756039 2055367> (DF)
16:24:52.517284 owl.rsync > elm.1216: P 76839:78287(1448) ack 31377430 win 
31856 <nop,nop,timestamp 528756057 2055367> (DF)
16:24:52.517673 elm.1216 > owl.rsync: . ack 78287 win 1448 <nop,nop,timestamp 
2055384 528756057> (DF)
16:24:52.517697 owl.rsync > elm.1216: . 78287:79735(1448) ack 31377430 win 
31856 <nop,nop,timestamp 528756057 2055367> (DF)
16:24:52.538760 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055387 528756057> (DF)
16:24:52.538849 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
28960 <nop,nop,timestamp 528756059 2055387> (DF)
16:24:52.539204 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055387 528756059> (DF)
16:24:52.737310 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756079 2055387> (DF)
16:24:52.737680 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055406 528756079> (DF)
16:24:52.938772 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055427 528756079> (DF)
16:24:52.938803 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756099 2055387> (DF)
16:24:52.938904 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055427 528756079> (DF)
16:24:53.137279 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756119 2055387> (DF)
16:24:53.137629 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055446 528756119> (DF)
16:24:53.738854 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055507 528756119> (DF)
16:24:53.738880 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756179 2055387> (DF)
16:24:53.739000 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055507 528756119> (DF)
16:24:53.937279 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756199 2055387> (DF)
16:24:53.937625 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055526 528756199> (DF)
16:24:55.338968 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055667 528756199> (DF)
16:24:55.339047 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756339 2055387> (DF)
16:24:55.339177 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055667 528756199> (DF)
16:24:55.537284 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756359 2055387> (DF)
16:24:55.537632 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055686 528756359> (DF)
16:24:58.539180 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2055987 528756359> (DF)
16:24:58.539212 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528756659 2055387> (DF)
16:24:58.539333 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2055987 528756359> (DF)
16:24:58.737280 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528756679 2055387> (DF)
16:24:58.737628 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056006 528756679> (DF)
16:25:04.939591 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2056627 528756679> (DF)
16:25:04.939642 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528757299 2055387> (DF)
16:25:04.939772 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056627 528756679> (DF)
16:25:05.137294 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528757319 2055387> (DF)
16:25:05.137695 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2056646 528757319> (DF)
16:25:17.740386 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2057907 528757319> (DF)
16:25:17.740417 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528758579 2055387> (DF)
16:25:17.740529 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2057907 528757319> (DF)
16:25:17.937282 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528758599 2055387> (DF)
16:25:17.937630 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2057926 528758599> (DF)
16:25:43.342057 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2060467 528758599> (DF)
16:25:43.342092 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528761139 2055387> (DF)
16:25:43.342203 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2060467 528758599> (DF)
16:25:43.537284 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528761159 2055387> (DF)
16:25:43.537632 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2060486 528761159> (DF)
16:26:34.545390 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2065587 528761159> (DF)
16:26:34.545479 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528766259 2055387> (DF)
16:26:34.545590 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2065587 528761159> (DF)
16:26:34.737322 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528766279 2055387> (DF)
16:26:34.737690 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2065606 528766279> (DF)
16:28:16.952043 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2075827 528766279> (DF)
16:28:16.952100 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528776500 2055387> (DF)
16:28:16.952227 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2075827 528766279> (DF)
16:28:17.137283 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528776519 2055387> (DF)
16:28:17.137635 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2075845 528776519> (DF)
16:30:16.959839 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2087827 528776519> (DF)
16:30:16.959900 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528788501 2055387> (DF)
16:30:16.960021 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2087827 528776519> (DF)
16:30:17.137286 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528788519 2055387> (DF)
16:30:17.137636 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2087844 528788519> (DF)
16:32:16.967633 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2099827 528788519> (DF)
16:32:16.967689 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528800502 2055387> (DF)
16:32:16.967812 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2099827 528788519> (DF)
16:32:17.137285 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528800519 2055387> (DF)
16:32:17.137634 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2099844 528800519> (DF)
16:34:16.975434 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2111827 528800519> (DF)
16:34:16.975505 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528812502 2055387> (DF)
16:34:16.975640 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2111827 528800519> (DF)
16:34:17.137284 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528812519 2055387> (DF)
16:34:17.137656 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2111843 528812519> (DF)
16:36:16.983199 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2123827 528812519> (DF)
16:36:16.983264 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528824503 2055387> (DF)
16:36:16.983391 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2123827 528812519> (DF)
16:36:17.137283 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528824519 2055387> (DF)
16:36:17.137634 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2123842 528824519> (DF)
16:38:16.990990 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2135827 528824519> (DF)
16:38:16.991058 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528836504 2055387> (DF)
16:38:16.991184 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2135827 528824519> (DF)
16:38:17.137283 owl.rsync > elm.1216: . 79735:81183(1448) ack 31383222 win 
31856 <nop,nop,timestamp 528836519 2055387> (DF)
16:38:17.137632 elm.1216 > owl.rsync: . ack 79735 win 0 <nop,nop,timestamp 
2135841 528836519> (DF)
16:40:16.998785 elm.1216 > owl.rsync: P 31377430:31378878(1448) ack 79735 win 0 
<nop,nop,timestamp 2147827 528836519> (DF)
16:40:16.998866 owl.rsync > elm.1216: . ack 31383222 win 31856 
<nop,nop,timestamp 528848505 2055387> (DF)
16:40:16.999003 elm.1216 > owl.rsync: R 2680405324:2680405324(0) win 0
16:40:17.000988 elm.1216 > owl.rsync: R 31436798:31436798(0) ack 79735 win 
31856 <nop,nop,timestamp 2147827 528836519> (DF)