Hello again,
to give a short summary; I contacted this list to ask for help with
diagnosing a problem with a co-located server (accessible at
http://stbgo.org) running FreeBSD 6.1. When I swamp it with requests
(simply, lynx -dump http://stbgo.org > /dev/null in a loop)
some responses take 90 seconds -- far too long. This is reproducible,
but seemingly not from other source addresses - only my own (home)
machine, 64.114.83.92
The recommendations have been to look at the traceroute output, and at
tcpdump from both ends; the tcpdump output was so far only available
from the client side, since the server's kernel didn't support
tcpdump. (Also, to "swamp" a different port and see the result -
planned next step)
The traceroute brought up a host with name
a.core.65-110-0-1.van.data-fortress.com which sits between my server
and the Internet. (As far as I can tell, this looks legitimate. The
co-location provider says their machines perform no filtering)
Traceroute from the client is not available; this service provider
blocked it for some reason, and I can live without it. (tcptraceroute
was suggested, but that gave no meaningful output; I may try again
from a different machine on the local network)
Now to where I got in the mean time.
I recompiled the server's kernel so that tcpdump is available.
Client tcpdump command
-----------------------------------------------------------------------------
$ sudo /usr/sbin/tcpdump -n -s 1600 -w clientside.dmp host stbgo.org
tcpdump: listening on eth0
398 packets received by filter
0 packets dropped by kernel
Server tcpdump command
---------------------------------------------------------------
$ sudo /usr/sbin/tcpdump -n -s 1600 -w /tmp/serverside.dmp
tcpdump: listening on bge0, link-type EN10MB (Ethernet), capture size 1600 bytes
Hm, dispatch protocol error: type 3 plen 4
302 packets captured
303 packets received by filter
0 packets dropped by kernel
During the times that these two commands ran, this was executed on the client.
Client swamping command
----------------------------------------------------------------
$ ruby o
0 : Mon Jan 01 14:09:38 PST 2007 -- done at Mon Jan 01 14:09:39 PST
2007. Took 0.532589
1 : Mon Jan 01 14:09:39 PST 2007 -- done at Mon Jan 01 14:09:39 PST
2007. Took 0.368819
2 : Mon Jan 01 14:09:39 PST 2007 -- done at Mon Jan 01 14:09:39 PST
2007. Took 0.352839
3 : Mon Jan 01 14:09:39 PST 2007 -- done at Mon Jan 01 14:09:40 PST
2007. Took 0.45799
4 : Mon Jan 01 14:09:40 PST 2007 -- done at Mon Jan 01 14:09:40 PST
2007. Took 0.369304
5 : Mon Jan 01 14:09:40 PST 2007 -- done at Mon Jan 01 14:09:41 PST
2007. Took 0.446588
6 : Mon Jan 01 14:09:41 PST 2007 -- done at Mon Jan 01 14:09:41 PST
2007. Took 0.345532
7 : Mon Jan 01 14:09:41 PST 2007 -- done at Mon Jan 01 14:09:41 PST
2007. Took 0.354955
8 : Mon Jan 01 14:09:41 PST 2007 -- done at Mon Jan 01 14:09:42 PST
2007. Took 0.465013
9 : Mon Jan 01 14:09:42 PST 2007 -- done at Mon Jan 01 14:09:42 PST
2007. Took 0.431748
10 : Mon Jan 01 14:09:42 PST 2007 -- done at Mon Jan 01 14:09:43 PST
2007. Took 0.368716
11 : Mon Jan 01 14:09:43 PST 2007 -- done at Mon Jan 01 14:09:43 PST
2007. Took 0.451658
12 : Mon Jan 01 14:09:43 PST 2007 -- done at Mon Jan 01 14:11:17 PST
2007. Took 93.492797
13 : Mon Jan 01 14:11:17 PST 2007 -- done at Mon Jan 01 14:11:17 PST
2007. Took 0.425495
14 : Mon Jan 01 14:11:17 PST 2007 -- done at Mon Jan 01 14:11:17 PST
2007. Took 0.430457
The "swamping script - o -" accesses the webserver 15 times in a loop
without pausing, and records the elapsed time. Note #12 took 93.49
seconds
Looking at the tcpdump dump files with tcptrace I find these connection entries
--- (Client side) ---
Ostermann's tcptrace -- version 6.6.7 -- Thu Nov 4, 2004
398 packets seen, 398 TCP packets traced
elapsed wallclock time: 0:00:00.109089, 3648 pkts/sec analyzed
trace file elapsed time: 0:02:12.449926
TCP connection info:
16 TCP connections traced:
TCP connection 1:
host a: sucrose.sugarmotor.net:35012
host b: vps-18-138.virtualprivateservers.ca:pcanywherestat
complete conn: no (SYNs: 0) (FINs: 0)
first packet: Mon Jan 1 14:09:14.224706 2007
last packet: Mon Jan 1 14:11:26.674632 2007
elapsed time: 0:02:12.449926
total packets: 137
filename: /tmp/clientside.dmp
a->b: b->a:
total packets: 90 total packets: 47
ack pkts sent: 90 ack pkts sent: 47
pure acks sent: 47 pure acks sent: 0
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 2240 unique bytes sent: 2480
actual data pkts: 43 actual data pkts: 47
actual data bytes: 2240 actual data bytes: 2480
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 43 pushed data pkts: 47
SYN/FIN pkts sent: 0/0 SYN/FIN pkts sent: 0/0
req 1323 ws/ts: N/Y req 1323 ws/ts: N/Y
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 0 bytes mss requested: 0 bytes
max segm size: 224 bytes max segm size: 128 bytes
min segm size: 48 bytes min segm size: 32 bytes
avg segm size: 52 bytes avg segm size: 52 bytes
max win adv: 19856 bytes max win adv: 33304 bytes
min win adv: 19856 bytes min win adv: 33304 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 19856 bytes avg win adv: 33304 bytes
initial window: 48 bytes initial window: 0 bytes
initial window: 1 pkts initial window: 0 pkts
ttl stream length: NA ttl stream length: NA
missed data: NA missed data: NA
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 132.431 secs data xmit time: 132.434 secs
idletime max: 99997.8 ms idletime max: 100015.9 ms
throughput: 17 Bps throughput: 19 Bps
================================
TCP connection 2:
host c: sucrose.sugarmotor.net:35041
host d: vps-18-138.virtualprivateservers.ca:80
complete conn: yes
first packet: Mon Jan 1 14:09:38.899996 2007
last packet: Mon Jan 1 14:09:39.215879 2007
elapsed time: 0:00:00.315883
total packets: 17
filename: /tmp/clientside.dmp
c->d: d->c:
total packets: 9 total packets: 8
ack pkts sent: 8 ack pkts sent: 8
pure acks sent: 5 pure acks sent: 2
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 2500 unique bytes sent: 3750
actual data pkts: 2 actual data pkts: 5
actual data bytes: 2500 actual data bytes: 3750
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 1 pushed data pkts: 3
SYN/FIN pkts sent: 1/1 SYN/FIN pkts sent: 1/1
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 0
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 1460 bytes mss requested: 1460 bytes
max segm size: 1448 bytes max segm size: 1448 bytes
min segm size: 1052 bytes min segm size: 65 bytes
avg segm size: 1249 bytes avg segm size: 749 bytes
max win adv: 14480 bytes max win adv: 66608 bytes
min win adv: 5840 bytes min win adv: 65556 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 9148 bytes avg win adv: 66457 bytes
initial window: 2500 bytes initial window: 189 bytes
initial window: 2 pkts initial window: 1 pkts
ttl stream length: 2500 bytes ttl stream length: 3750 bytes
missed data: 0 bytes missed data: 0 bytes
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.000 secs data xmit time: 0.026 secs
idletime max: 257.0 ms idletime max: 203.1 ms
throughput: 7914 Bps throughput: 11871 Bps
=====
:
:
...12 similar connections...
:
:
TCP connection 14:
host aa: sucrose.sugarmotor.net:35053
host ab: vps-18-138.virtualprivateservers.ca:80
complete conn: yes
first packet: Mon Jan 1 14:09:43.755058 2007
last packet: Mon Jan 1 14:11:17.122339 2007
elapsed time: 0:01:33.367281
total packets: 23
filename: /tmp/clientside.dmp
aa->ab: ab->aa:
total packets: 14 total packets: 9
ack pkts sent: 8 ack pkts sent: 9
pure acks sent: 5 pure acks sent: 3
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 2500 unique bytes sent: 3750
actual data pkts: 2 actual data pkts: 5
actual data bytes: 2500 actual data bytes: 3750
rexmt data pkts: 5 rexmt data pkts: 0
rexmt data bytes: 5 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 1 pushed data pkts: 3
SYN/FIN pkts sent: 6/1 SYN/FIN pkts sent: 1/1
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 0
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 1460 bytes mss requested: 1460 bytes
max segm size: 1448 bytes max segm size: 1448 bytes
min segm size: 1052 bytes min segm size: 65 bytes
avg segm size: 1249 bytes avg segm size: 749 bytes
max win adv: 14480 bytes max win adv: 66608 bytes
min win adv: 5840 bytes min win adv: 66606 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 9148 bytes avg win adv: 66607 bytes
initial window: 1448 bytes initial window: 189 bytes
initial window: 1 pkts initial window: 1 pkts
ttl stream length: 2500 bytes ttl stream length: 3750 bytes
missed data: 0 bytes missed data: 0 bytes
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.137 secs data xmit time: 0.027 secs
idletime max: 48000.0 ms idletime max: 139.8 ms
throughput: 27 Bps throughput: 40 Bps
What is TCP Connection 1 about ("PCanywhere"); why for 2 minutes?
Could it be the ssh shell which is open at the same time?
TCP Connection 14 seems to be the one corresponding to the ca. 90
seconds response time recorded by the ruby command. It is the only one
with a line
SYN/FIN pkts sent: 6/1
All others have 1/1 in the first column (or 0/0 for the PCAnywhere connection)
To match things up, below is the excerpt from the serverside dump for
the same connections.
Should I look closely into the dump files themselves to see further?
What to look for? Or can anything be concluded with this alone?
Thanks a lot, and happy new year --
Stephan
--- (Server side) ---
TCP connection 1:
host a: vps-18-138.virtualprivateservers.ca:pcanywherestat
host b: zz83092.cipherkey.net:55116
complete conn: no (SYNs: 0) (FINs: 0)
first packet: Mon Jan 1 14:13:20.414784 2007
last packet: Mon Jan 1 14:15:00.446913 2007
elapsed time: 0:01:40.032128
total packets: 5
filename: /tmp/serverside.dmp
a->b: b->a:
total packets: 2 total packets: 3
ack pkts sent: 2 ack pkts sent: 3
pure acks sent: 0 pure acks sent: 2
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 160 unique bytes sent: 224
actual data pkts: 2 actual data pkts: 1
actual data bytes: 160 actual data bytes: 224
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 2 pushed data pkts: 1
SYN/FIN pkts sent: 0/0 SYN/FIN pkts sent: 0/0
req 1323 ws/ts: N/Y req 1323 ws/ts: N/Y
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 0 bytes mss requested: 0 bytes
max segm size: 128 bytes max segm size: 224 bytes
min segm size: 32 bytes min segm size: 224 bytes
avg segm size: 79 bytes avg segm size: 223 bytes
max win adv: 33304 bytes max win adv: 19856 bytes
min win adv: 33304 bytes min win adv: 19856 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 33304 bytes avg win adv: 19856 bytes
initial window: 128 bytes initial window: 0 bytes
initial window: 1 pkts initial window: 0 pkts
ttl stream length: NA ttl stream length: NA
missed data: NA missed data: NA
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 100.016 secs data xmit time: 0.000 secs
idletime max: 100015.6 ms idletime max: 99999.4 ms
throughput: 2 Bps throughput: 2 Bps
================================
TCP connection 2:
host c: zz83092.cipherkey.net:55402
host d: vps-18-138.virtualprivateservers.ca:80
complete conn: yes
first packet: Mon Jan 1 14:13:26.336098 2007
last packet: Mon Jan 1 14:13:26.637267 2007
elapsed time: 0:00:00.301169
total packets: 17
filename: /tmp/serverside.dmp
c->d: d->c:
total packets: 9 total packets: 8
ack pkts sent: 8 ack pkts sent: 8
pure acks sent: 5 pure acks sent: 2
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 2500 unique bytes sent: 3750
actual data pkts: 2 actual data pkts: 5
actual data bytes: 2500 actual data bytes: 3750
rexmt data pkts: 0 rexmt data pkts: 0
rexmt data bytes: 0 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 1 pushed data pkts: 3
SYN/FIN pkts sent: 1/1 SYN/FIN pkts sent: 1/1
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 0
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 1460 bytes mss requested: 1460 bytes
max segm size: 1448 bytes max segm size: 1448 bytes
min segm size: 1052 bytes min segm size: 65 bytes
avg segm size: 1249 bytes avg segm size: 749 bytes
max win adv: 14480 bytes max win adv: 66608 bytes
min win adv: 5840 bytes min win adv: 65556 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 9148 bytes avg win adv: 66457 bytes
initial window: 2500 bytes initial window: 2237 bytes
initial window: 2 pkts initial window: 3 pkts
ttl stream length: 2500 bytes ttl stream length: 3750 bytes
missed data: 0 bytes missed data: 0 bytes
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.015 secs data xmit time: 0.017 secs
idletime max: 218.1 ms idletime max: 201.4 ms
throughput: 8301 Bps throughput: 12451 Bps
==========
:
:
:
TCP connection 14:
host aa: zz83092.cipherkey.net:55402
host ab: vps-18-138.virtualprivateservers.ca:80
complete conn: yes
first packet: Mon Jan 1 14:13:31.191783 2007
last packet: Mon Jan 1 14:15:04.543351 2007
elapsed time: 0:01:33.351567
total packets: 23
filename: /tmp/serverside.dmp
aa->ab: ab->aa:
total packets: 14 total packets: 9
ack pkts sent: 8 ack pkts sent: 9
pure acks sent: 5 pure acks sent: 3
sack pkts sent: 0 sack pkts sent: 0
dsack pkts sent: 0 dsack pkts sent: 0
max sack blks/ack: 0 max sack blks/ack: 0
unique bytes sent: 2500 unique bytes sent: 3750
actual data pkts: 2 actual data pkts: 5
actual data bytes: 2500 actual data bytes: 3750
rexmt data pkts: 5 rexmt data pkts: 0
rexmt data bytes: 5 rexmt data bytes: 0
zwnd probe pkts: 0 zwnd probe pkts: 0
zwnd probe bytes: 0 zwnd probe bytes: 0
outoforder pkts: 0 outoforder pkts: 0
pushed data pkts: 1 pushed data pkts: 3
SYN/FIN pkts sent: 6/1 SYN/FIN pkts sent: 1/1
req 1323 ws/ts: Y/Y req 1323 ws/ts: Y/Y
adv wind scale: 0 adv wind scale: 1
req sack: Y req sack: Y
sacks sent: 0 sacks sent: 0
urgent data pkts: 0 pkts urgent data pkts: 0 pkts
urgent data bytes: 0 bytes urgent data bytes: 0 bytes
mss requested: 1460 bytes mss requested: 1460 bytes
max segm size: 1448 bytes max segm size: 1448 bytes
min segm size: 1052 bytes min segm size: 65 bytes
avg segm size: 1249 bytes avg segm size: 749 bytes
max win adv: 14480 bytes max win adv: 66608 bytes
min win adv: 5840 bytes min win adv: 66606 bytes
zero win adv: 0 times zero win adv: 0 times
avg win adv: 9148 bytes avg win adv: 66607 bytes
initial window: 1448 bytes initial window: 2237 bytes
initial window: 1 pkts initial window: 3 pkts
ttl stream length: 2500 bytes ttl stream length: 3750 bytes
missed data: 0 bytes missed data: 0 bytes
truncated data: 0 bytes truncated data: 0 bytes
truncated packets: 0 pkts truncated packets: 0 pkts
data xmit time: 0.131 secs data xmit time: 0.020 secs
idletime max: 47998.4 ms idletime max: 141.9 ms
throughput: 27 Bps throughput: 40 Bps
_______________________________________________
freebsd-net@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-net
To unsubscribe, send any mail to "[EMAIL PROTECTED]"
