Skip to Content.
Sympa Menu

ndt-users - RE: Error running web100 3.5.0

Subject: ndt-users list created

List archive

RE: Error running web100 3.5.0


Chronological Thread 
  • From: "Galuschka Christoph" <>
  • To: "Richard Carlson" <>
  • Cc: <>
  • Subject: RE: Error running web100 3.5.0
  • Date: Sat, 29 Aug 2009 09:16:20 +0200

Title: Re: Error running web100 3.5.0
Hello Richard,
 
thanks for posting the new releases.
I've installed 3.5.6 and I still get some errors resulting in an incomplete measurement. Here is the output from web100srv:
>>
ANL/Internet2 NDT ver 3.5.6
        Variables file = /usr/local/ndt/web100_variables
        log file = /usr/local/ndt/web100srv.log
        Debug level set to 5
Send buffer initialized to 16384, Receive buffer initialized to 87380
server ready on port 3001
web100_init() read 69 variables from file
Generated iflist with device=eth2 and if_speed=7
nothing in queue
Timer not running, waiting for new connection
New connection received, waiting for accept() to complete
New connection received from [10.108.0.15].
Parent process spawned child = 3741
Parent thinks pipe() returned fd0=6, fd1=7
Child thinks pipe() returned fd0=6, fd1=7 for pid=0
<<< recv_msg: type=2, len=1
initialize_tests returned old/new client = 1, test_suite = 1 8 2 4
Incrementing waiting variable now = 1
Telling client 3741 testing will begin now
>>> send_msg: type=1, len=1
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
extracting test_suite ' 1 8 2 4' and t_opts '1f' from buff 'go 31 1 8 2 4'
Child process 3741 started
>>> send_msg: type=2, len=6
run_test() routine, asking for test_suite =  1 8 2 4
>>> send_msg: type=2, len=8
Starting test suite:
 > Middlebox test
 > Simple firewall test
 > C2S throughput test
 > S2C throughput test
 <-- Middlebox test -->
KillHung(): returned non-0 response, nothing to kill or kill failed
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3003
>>> send_msg: type=3, len=4
Looking for Web100 data on socketid 6
Server: 10.11.215.13;3003 Client: 10.108.0.15;3445 1456;-1;-1;
Sending 1456 Byte packets over the network
Setting Cwnd Limit to 2912 octets
Signal 17 received by process 3741
now = 1251529359 Process started at 1251529356, run time = 3
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=5, len=36
<<< recv_msg: type=5, len=18
CWND limited throughput = 43453 kbps (43453.261783901384)
>>> send_msg: type=6, len=0
 <-------------------->
 <-- Simple firewall test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 35753
  -- time: 1
>>> send_msg: type=3, len=7
now = 1251529362 Process started at 1251529356, run time = 6
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
<<< recv_msg: type=5, len=4
  -- oport: 3448
>>> send_msg: type=4, len=0
Send buffer initialized to 16384, Receive buffer initialized to 87380
>>> send_msg: type=5, len=20
<<< recv_msg: type=5, len=20
>>> send_msg: type=5, len=1
>>> send_msg: type=6, len=0
 <-------------------------->
 <-- C2S throughput test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3002
listening for Inet connection on testOptions->c2ssockfd, fd=3
Sending 'GO' signal, to tell client to head for the next test
>>> send_msg: type=3, len=4
C2S test Child thinks pipe() returned fd0=8, fd1=9
Unknown address family=17 found
IPv4 interface found address=10.11.215.13
IPv4 address match, setting device to 'eth2'
Opening network interface 'eth2' for packet-pair timing
pcap_open_live() returned pointer 0x8088868
installing pkt filter for 'host 10.108.0.15 and port 3451'
Initial pkt src data = "806b5c4C2S test Parent thinks pipe() returned fd0=8, fd1=9
now = 1251529365 Process started at 1251529356, run time = 9
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=4, len=0
New IPv4 packet trace started -- initializing counters
now = 1251529368 Process started at 1251529356, run time = 12
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251529371 Process started at 1251529356, run time = 15
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251529374 Process started at 1251529356, run time = 18
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
690876 kbps outbound
>>> send_msg: type=5, len=6
Signal USR1(10) sent to child [3744]
Signal 10 received by process 3744
Received SIGUSRx signal terminating data collection loop for pid=3744
Sending pkt-pair data back to parent on pipe 8, 9
fwd.saddr = f006c0a:3451, rev.saddr = dd70b0a:3002
01:02:46.369960   10.108.0.15:3451 --> 10.11.215.13:3002 Collected pkt-pair data max = 334203
01:02:46.369960   10.11.215.13:3002 --> 10.108.0.15:3451 Collected pkt-pair data max = 81670
128 bytes read '  1 0 0 0 19 12738 129915 1642 108553 334203 0 6705 219.82 0 0 0 1 0 7' from monitor pipe
128 bytes read '  0 0 1 0 3 31 49754 81670 19693 11227 1 0 581.71 21 1 162358 0 1 7' from monitor pipe
>>> send_msg: type=6, len=0
Signal 11 received by process 3744
Signal 17 received by process 3741
 <------------------------->
 <-- S2C throughput test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3003
>>> send_msg: type=3, len=4
waiting for data on testOptions->s2csockfd
S2C test Child thinks pipe() returned fd0=8, fd1=9
Unknown address family=17 found
IPv4 interface found address=10.11.215.13
IPv4 address match, setting device to 'eth2'
Opening network interface 'eth2' for packet-pair timing
pcap_open_live() returned pointer 0x808da40
installing pkt filter for 'host 10.108.0.15 and port 3461'
Initial pkt src data = "806b5c4Signal 17 received by process 3741
>>> send_msg: type=4, len=0
New IPv4 packet trace started -- initializing counters
now = 1251529377 Process started at 1251529356, run time = 21
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251529380 Process started at 1251529356, run time = 24
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251529383 Process started at 1251529356, run time = 27
Timer expired while waiting for a new connection
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=5, len=23
sent 688488448 bytes to client in 10.00 seconds
Buffer control counters Total = 84044, new data = "0," Draining Queue = 0
Signal USR2(12) sent to child [3746]
Signal 12 received by process 3746
Received SIGUSRx signal terminating data collection loop for pid=3746
Sending pkt-pair data back to parent on pipe 8, 9
fwd.saddr = dd70b0a:3003, rev.saddr = f006c0a:3461
01:02:56.724367   10.11.215.13:3003 --> 10.108.0.15:3461 Collected pkt-pair data max = 18667
01:02:56.724367   10.108.0.15:3461 --> 10.11.215.13:3003 Collected pkt-pair data max = 65475
Read '  1 0 0 0 4 661 18667 6971 5501 5721 0 5377 976.37 0 0 0 1 0 7' from monitor pipe
Read '  0 0 0 1 367 9334 40681 26321 35413 65475 39990 34285 663.83 39864 40036 171967 0 39990 7' from monitor pipe
550764 kbps inbound
libweb100: warning: accessing depricated variable AckPktsIn
Variable 0 (AckPktsIn): web100_snap_read(): invalid arguments
libweb100: warning: accessing depricated variable AckPktsOut
Variable 1 (AckPktsOut): web100_snap_read(): invalid arguments
Variable 2 (BytesRetrans): web100_snap_read(): invalid arguments
Variable 3 (CongAvoid): web100_snap_read(): invalid arguments
Variable 4 (CongestionOverCount): web100_snap_read(): invalid arguments
Variable 5 (CongestionSignals): web100_snap_read(): invalid arguments
Variable 6 (CountRTT): web100_snap_read(): invalid arguments
Variable 7 (CurCwnd): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=13
Variable 9 (CurRTO): web100_snap_read(): invalid arguments
Variable 10 (CurRwinRcvd): web100_snap_read(): invalid arguments
Variable 11 (CurRwinSent): web100_snap_read(): invalid arguments
Variable 12 (CurSsthresh): web100_snap_read(): invalid arguments
Variable 13 (CwndRestores) not found in KIS
Variable 14 (DSACKDups): web100_snap_read(): invalid arguments
Variable 15 (DataBytesIn): web100_snap_read(): invalid arguments
Variable 16 (DataBytesOut): web100_snap_read(): invalid arguments
Variable 17 (DataPktsIn): web100_snap_read(): invalid arguments
Variable 18 (DataPktsOut): web100_snap_read(): invalid arguments
Variable 19 (DupAcksIn): web100_snap_read(): invalid arguments
Variable 20 (ECNEnabled): web100_snap_read(): invalid arguments
Variable 21 (FastRetran): web100_snap_read(): invalid arguments
Variable 22 (MaxCaCwnd) not found in KIS
Variable 23 (MaxCwnd): web100_snap_read(): invalid arguments
Variable 24 (MaxMSS): web100_snap_read(): invalid arguments
Variable 25 (MaxRTO): web100_snap_read(): invalid arguments
Variable 26 (MaxRTT): web100_snap_read(): invalid arguments
Variable 27 (MaxRwinRcvd): web100_snap_read(): invalid arguments
Variable 28 (MaxRwinSent): web100_snap_read(): invalid arguments
Variable 29 (MaxSsthresh): web100_snap_read(): invalid arguments
Variable 30 (MaxSaCwnd) not found in KIS
Variable 31 (MinMSS): web100_snap_read(): invalid arguments
Variable 32 (MinRTO): web100_snap_read(): invalid arguments
Variable 33 (MinRTT): web100_snap_read(): invalid arguments
Variable 34 (MinRwinRcvd): web100_snap_read(): invalid arguments
Variable 35 (MinRwinSent): web100_snap_read(): invalid arguments
Variable 36 (NagleEnabled): web100_snap_read(): invalid arguments
Variable 37 (OtherReductions): web100_snap_read(): invalid arguments
Variable 38 (PktsIn): web100_snap_read(): invalid arguments
Variable 39 (PktsOut): web100_snap_read(): invalid arguments
Variable 40 (PktsRetrans): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
Variable 42 (RcvWinScale): web100_snap_read(): invalid arguments
Variable 43 (SACKEnabled): web100_snap_read(): invalid arguments
Variable 44 (SACKsRcvd): web100_snap_read(): invalid arguments
Variable 45 (SendStall): web100_snap_read(): invalid arguments
Variable 46 (SlowStart): web100_snap_read(): invalid arguments
Variable 47 (SampleRTT): web100_snap_read(): invalid arguments
Variable 48 (SmoothedRTT): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=17
Variable 50 (SndWinScale): web100_snap_read(): invalid arguments
Variable 51 (SndLimTimeRwin): web100_snap_read(): invalid arguments
Variable 52 (SndLimTimeCwnd): web100_snap_read(): invalid arguments
Variable 53 (SndLimTimeSender): web100_snap_read(): invalid arguments
Variable 54 (SndLimTransRwin): web100_snap_read(): invalid arguments
Variable 55 (SndLimTransCwnd): web100_snap_read(): invalid arguments
Variable 56 (SndLimTransSender): web100_snap_read(): invalid arguments
Variable 57 (SndLimBytesRwin): web100_snap_read(): invalid arguments
Variable 58 (SndLimBytesCwnd): web100_snap_read(): invalid arguments
Variable 59 (SndLimBytesSender): web100_snap_read(): invalid arguments
Variable 60 (SubsequentTimeouts): web100_snap_read(): invalid arguments
Variable 61 (SumRTT): web100_snap_read(): invalid arguments
Variable 62 (Timeouts): web100_snap_read(): invalid arguments
Variable 63 (TimestampsEnabled): web100_snap_read(): invalid arguments
Variable 64 (WinScaleRcvd): web100_snap_read(): invalid arguments
Variable 65 (WinScaleSent): web100_snap_read(): invalid arguments
Variable 66 (DupAcksOut): web100_snap_read(): invalid arguments
Variable 67 (StartTimeUsec): web100_snap_read(): invalid arguments
Variable 68 (Duration): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=21
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=15
Variable 8 (CurMSS): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=19
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=24
Variable 13 (CwndRestores) not found in KIS
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=24
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=20
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=14
Variable 22 (MaxCaCwnd) not found in KIS
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=10
>>> send_msg: type=5, len=19
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=15
Variable 30 (MaxSaCwnd) not found in KIS
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=10
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=15
Variable 41 (X_Rcvbuf): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=15
Variable 49 (X_Sndbuf): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=24
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=26
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=25
>>> send_msg: type=5, len=27
>>> send_msg: type=5, len=27
>>> send_msg: type=5, len=29
>>> send_msg: type=5, len=22
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=21
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=22
>>> send_msg: type=5, len=19
Signal 11 received by process 3746
Signal 17 received by process 3741
Protocol error!
>>> send_msg: type=7, len=61
S2C throughput test FAILED!
Finished testing C2S = 690.88 Mbps, S2C = -0.00 Mbps
Client --> Server data detects link = OC-12
Client <-- Server Ack's detect link = Gigabit Ethernet
Server --> Client data detects link = OC-12
Server <-- Client Ack's detect link = OC-12
CWND limited test = 43453.26 while unlimited = -0.71
Better throughput when CWND is limited, may be duplex mismatch
>>> send_msg: type=8, len=42
>>> send_msg: type=8, len=76
>>> send_msg: type=8, len=89
>>> send_msg: type=8, len=77
>>> send_msg: type=8, len=82
>>> send_msg: type=8, len=53
>>> send_msg: type=9, len=0
Opened '/usr/local/ndt/serverdata/2009/08/29/20090829T07:02:36.826169000Z_10.108.0.15:3444.meta' metadata log file
Successfully returned from run_test() routine
Signal 17 received by process 3740
now = 1251529386 Process started at 1251529356, run time = 30
Select exited with rc = -1
Queue pointer = 3741, testing = 1, waiting = 1, zombie_check = 0
Received SIGCHLD signal for active web100srv process [3740]
wait3() returned 0 for PID=3741
wexitstatus = '0'
Attempting to clean up child 3741, head pid = 3741
Child process 3741 causing head pointer modification
Removing Child from head, decrementing waiting now = 0
Timer not running, waiting for new connection
>>
This is the result from the browser:
>>
Connecting to '10.11.215.13' [/10.11.215.13] to run test
Connected to: 10.11.215.13  --  Using IPv4 address
Checking for Middleboxes . . . . . . . . . . . . . . . . . .  Done
checking for firewalls . . . . . . . . . . . . . . . . . . .  Done
running 10s outbound test (client-to-server [C2S]) . . . . . 690.87Mb/s
running 10s inbound test (server-to-client [S2C]) . . . . . . 550.79Mb/s
S2C throughput test: Received wrong type of the message
ERROR MSG: Server (S2C throughput test): Invalid S2C throughput received
S2C throughput test FAILED!
The slowest link in the end-to-end path is a a 622 Mbps OC-12 subnet
>>
 
After running the test I re-read your email and checked src/testoptions.c line 730 about the comment wait(NULL). I see the /* */ are still there so I removed them and recompiled everything. This did not help very much - here is output from web100srv with the /* */ removed:
>>
ANL/Internet2 NDT ver 3.5.6
        Variables file = /usr/local/ndt/web100_variables
        log file = /usr/local/ndt/web100srv.log
        Debug level set to 5
Send buffer initialized to 16384, Receive buffer initialized to 87380
server ready on port 3001
web100_init() read 69 variables from file
Generated iflist with device=eth2 and if_speed=7
nothing in queue
Timer not running, waiting for new connection
New connection received, waiting for accept() to complete
New connection received from [10.108.0.15].
Child thinks pipe() returned fd0=6, fd1=7 for pid=0
Parent process spawned child = 8857
Parent thinks pipe() returned fd0=6, fd1=7
<<< recv_msg: type=2, len=1
initialize_tests returned old/new client = 1, test_suite = 1 8 2 4
Incrementing waiting variable now = 1
Telling client 8857 testing will begin now
>>> send_msg: type=1, len=1
extracting test_suite ' 1 8 2 4' and t_opts '1f' from buff 'go 31 1 8 2 4'
Child process 8857 started
>>> send_msg: type=2, len=6
run_test() routine, asking for test_suite =  1 8 2 4
>>> send_msg: type=2, len=8
Starting test suite:
 > Middlebox test
 > Simple firewall test
 > C2S throughput test
 > S2C throughput test
 <-- Middlebox test -->
KillHung(): returned non-0 response, nothing to kill or kill failed
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3003
>>> send_msg: type=3, len=4
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
Looking for Web100 data on socketid 6
Server: 10.11.215.13;3003 Client: 10.108.0.15;4256 1456;-1;-1;
Sending 1456 Byte packets over the network
Setting Cwnd Limit to 2912 octets
Signal 17 received by process 8857
now = 1251530073 Process started at 1251530070, run time = 3
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=5, len=36
<<< recv_msg: type=5, len=17
CWND limited throughput = 43591 kbps (43590.52066715011)
>>> send_msg: type=6, len=0
 <-------------------->
 <-- Simple firewall test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 49050
  -- time: 1
>>> send_msg: type=3, len=7
now = 1251530076 Process started at 1251530070, run time = 6
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
<<< recv_msg: type=5, len=4
  -- oport: 4264
>>> send_msg: type=4, len=0
Send buffer initialized to 16384, Receive buffer initialized to 87380
>>> send_msg: type=5, len=20
<<< recv_msg: type=5, len=20
>>> send_msg: type=5, len=1
>>> send_msg: type=6, len=0
 <-------------------------->
 <-- C2S throughput test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3002
listening for Inet connection on testOptions->c2ssockfd, fd=3
Sending 'GO' signal, to tell client to head for the next test
>>> send_msg: type=3, len=4
C2S test Child thinks pipe() returned fd0=8, fd1=9
Unknown address family=17 found
IPv4 interface found address=10.11.215.13
IPv4 address match, setting device to 'eth2'
Opening network interface 'eth2' for packet-pair timing
pcap_open_live() returned pointer 0x80887b8
installing pkt filter for 'host 10.108.0.15 and port 4267'
Initial pkt src data = "806b5c4C2S test Parent thinks pipe() returned fd0=8, fd1=9
now = 1251530079 Process started at 1251530070, run time = 9
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=4, len=0
New IPv4 packet trace started -- initializing counters
now = 1251530082 Process started at 1251530070, run time = 12
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251530085 Process started at 1251530070, run time = 15
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251530088 Process started at 1251530070, run time = 18
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
702893 kbps outbound
>>> send_msg: type=5, len=6
Signal USR1(10) sent to child [8860]
Signal 10 received by process 8860
Received SIGUSRx signal terminating data collection loop for pid=8860
Sending pkt-pair data back to parent on pipe 8, 9
fwd.saddr = f006c0a:4267, rev.saddr = dd70b0a:3002
01:14:40.549642   10.108.0.15:4267 --> 10.11.215.13:3002 Collected pkt-pair data max = 333191
01:14:40.549642   10.11.215.13:3002 --> 10.108.0.15:4267 Collected pkt-pair data max = 81890
128 bytes read '  1 0 0 0 11 10000 137189 1828 114339 333191 0 6442 411.54 0 0 0 1 0 7' from monitor pipe
128 bytes read '  1 0 1 0 4 12 52207 81890 21152 11384 0 1 376.10 21 1 166629 0 0 7' from monitor pipe
>>> send_msg: type=6, len=0
Signal 11 received by process 8860
Signal 17 received by process 8857
 <------------------------->
 <-- S2C throughput test -->
Send buffer initialized to 16384, Receive buffer initialized to 87380
  -- port: 3003
>>> send_msg: type=3, len=4
waiting for data on testOptions->s2csockfd
S2C test Child thinks pipe() returned fd0=8, fd1=9
Unknown address family=17 found
IPv4 interface found address=10.11.215.13
IPv4 address match, setting device to 'eth2'
Opening network interface 'eth2' for packet-pair timing
pcap_open_live() returned pointer 0x808d988
installing pkt filter for 'host 10.108.0.15 and port 4275'
Initial pkt src data = "806b5c4Signal 17 received by process 8857
>>> send_msg: type=4, len=0
New IPv4 packet trace started -- initializing counters
now = 1251530091 Process started at 1251530070, run time = 21
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251530094 Process started at 1251530070, run time = 24
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251530097 Process started at 1251530070, run time = 27
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
now = 1251530100 Process started at 1251530070, run time = 30
Timer expired while waiting for a new connection
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Waiting for new connection, timer running
>>> send_msg: type=5, len=23
sent 682885120 bytes to client in 10.00 seconds
Buffer control counters Total = 83360, new data = "0," Draining Queue = 0
Signal USR2(12) sent to child [8862]
Signal 12 received by process 8862
Received SIGUSRx signal terminating data collection loop for pid=8862
Sending pkt-pair data back to parent on pipe 8, 9
fwd.saddr = dd70b0a:3003, rev.saddr = f006c0a:4275
01:14:51.024505   10.11.215.13:3003 --> 10.108.0.15:4275 Collected pkt-pair data max = 19773
01:14:51.024505   10.108.0.15:4275 --> 10.11.215.13:3003 Collected pkt-pair data max = 53278
Read '  1 0 0 0 117 210 19773 5859 8725 6585 1 1516 2353.39 0 0 0 1 0 7' from monitor pipe
Read '  0 0 1 0 461 9237 49287 32586 37351 53278 39346 24385 647.81 39209 39481 167242 0 39345 7' from monitor pipe
546250 kbps inbound
libweb100: warning: accessing depricated variable AckPktsIn
Variable 0 (AckPktsIn): web100_snap_read(): invalid arguments
libweb100: warning: accessing depricated variable AckPktsOut
Variable 1 (AckPktsOut): web100_snap_read(): invalid arguments
Variable 2 (BytesRetrans): web100_snap_read(): invalid arguments
Variable 3 (CongAvoid): web100_snap_read(): invalid arguments
Variable 4 (CongestionOverCount): web100_snap_read(): invalid arguments
Variable 5 (CongestionSignals): web100_snap_read(): invalid arguments
Variable 6 (CountRTT): web100_snap_read(): invalid arguments
Variable 7 (CurCwnd): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=13
Variable 9 (CurRTO): web100_snap_read(): invalid arguments
Variable 10 (CurRwinRcvd): web100_snap_read(): invalid arguments
Variable 11 (CurRwinSent): web100_snap_read(): invalid arguments
Variable 12 (CurSsthresh): web100_snap_read(): invalid arguments
Variable 13 (CwndRestores) not found in KIS
Variable 14 (DSACKDups): web100_snap_read(): invalid arguments
Variable 15 (DataBytesIn): web100_snap_read(): invalid arguments
Variable 16 (DataBytesOut): web100_snap_read(): invalid arguments
Variable 17 (DataPktsIn): web100_snap_read(): invalid arguments
Variable 18 (DataPktsOut): web100_snap_read(): invalid arguments
Variable 19 (DupAcksIn): web100_snap_read(): invalid arguments
Variable 20 (ECNEnabled): web100_snap_read(): invalid arguments
Variable 21 (FastRetran): web100_snap_read(): invalid arguments
Variable 22 (MaxCaCwnd) not found in KIS
Variable 23 (MaxCwnd): web100_snap_read(): invalid arguments
Variable 24 (MaxMSS): web100_snap_read(): invalid arguments
Variable 25 (MaxRTO): web100_snap_read(): invalid arguments
Variable 26 (MaxRTT): web100_snap_read(): invalid arguments
Variable 27 (MaxRwinRcvd): web100_snap_read(): invalid arguments
Variable 28 (MaxRwinSent): web100_snap_read(): invalid arguments
Variable 29 (MaxSsthresh): web100_snap_read(): invalid arguments
Variable 30 (MaxSaCwnd) not found in KIS
Variable 31 (MinMSS): web100_snap_read(): invalid arguments
Variable 32 (MinRTO): web100_snap_read(): invalid arguments
Variable 33 (MinRTT): web100_snap_read(): invalid arguments
Variable 34 (MinRwinRcvd): web100_snap_read(): invalid arguments
Variable 35 (MinRwinSent): web100_snap_read(): invalid arguments
Variable 36 (NagleEnabled): web100_snap_read(): invalid arguments
Variable 37 (OtherReductions): web100_snap_read(): invalid arguments
Variable 38 (PktsIn): web100_snap_read(): invalid arguments
Variable 39 (PktsOut): web100_snap_read(): invalid arguments
Variable 40 (PktsRetrans): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
Variable 42 (RcvWinScale): web100_snap_read(): invalid arguments
Variable 43 (SACKEnabled): web100_snap_read(): invalid arguments
Variable 44 (SACKsRcvd): web100_snap_read(): invalid arguments
Variable 45 (SendStall): web100_snap_read(): invalid arguments
Variable 46 (SlowStart): web100_snap_read(): invalid arguments
Variable 47 (SampleRTT): web100_snap_read(): invalid arguments
Variable 48 (SmoothedRTT): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=17
Variable 50 (SndWinScale): web100_snap_read(): invalid arguments
Variable 51 (SndLimTimeRwin): web100_snap_read(): invalid arguments
Variable 52 (SndLimTimeCwnd): web100_snap_read(): invalid arguments
Variable 53 (SndLimTimeSender): web100_snap_read(): invalid arguments
Variable 54 (SndLimTransRwin): web100_snap_read(): invalid arguments
Variable 55 (SndLimTransCwnd): web100_snap_read(): invalid arguments
Variable 56 (SndLimTransSender): web100_snap_read(): invalid arguments
Variable 57 (SndLimBytesRwin): web100_snap_read(): invalid arguments
Variable 58 (SndLimBytesCwnd): web100_snap_read(): invalid arguments
Variable 59 (SndLimBytesSender): web100_snap_read(): invalid arguments
Variable 60 (SubsequentTimeouts): web100_snap_read(): invalid arguments
Variable 61 (SumRTT): web100_snap_read(): invalid arguments
Variable 62 (Timeouts): web100_snap_read(): invalid arguments
Variable 63 (TimestampsEnabled): web100_snap_read(): invalid arguments
Variable 64 (WinScaleRcvd): web100_snap_read(): invalid arguments
Variable 65 (WinScaleSent): web100_snap_read(): invalid arguments
Variable 66 (DupAcksOut): web100_snap_read(): invalid arguments
Variable 67 (StartTimeUsec): web100_snap_read(): invalid arguments
Variable 68 (Duration): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=21
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=15
Variable 8 (CurMSS): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=19
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=19
Variable 13 (CwndRestores) not found in KIS
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=24
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=20
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=14
Variable 22 (MaxCaCwnd) not found in KIS
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=10
>>> send_msg: type=5, len=19
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=19
Variable 30 (MaxSaCwnd) not found in KIS
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=10
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=18
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=15
Variable 41 (X_Rcvbuf): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=13
>>> send_msg: type=5, len=15
Variable 49 (X_Sndbuf): web100_snap_read(): invalid arguments
>>> send_msg: type=5, len=16
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=24
>>> send_msg: type=5, len=26
>>> send_msg: type=5, len=22
>>> send_msg: type=5, len=23
>>> send_msg: type=5, len=25
>>> send_msg: type=5, len=27
>>> send_msg: type=5, len=27
>>> send_msg: type=5, len=29
>>> send_msg: type=5, len=22
>>> send_msg: type=5, len=15
>>> send_msg: type=5, len=12
>>> send_msg: type=5, len=21
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=17
>>> send_msg: type=5, len=14
>>> send_msg: type=5, len=22
>>> send_msg: type=5, len=19
Signal 11 received by process 8862
Signal 17 received by process 8857
Protocol error!
>>> send_msg: type=7, len=61
S2C throughput test FAILED!
Finished testing C2S = 702.89 Mbps, S2C = -0.00 Mbps
Client --> Server data detects link = OC-12
Client <-- Server Ack's detect link = Gigabit Ethernet
Server --> Client data detects link = OC-12
Server <-- Client Ack's detect link = OC-12
CWND limited test = 43590.52 while unlimited = -1.42
Better throughput when CWND is limited, may be duplex mismatch
>>> send_msg: type=8, len=42
>>> send_msg: type=8, len=76
>>> send_msg: type=8, len=89
>>> send_msg: type=8, len=77
>>> send_msg: type=8, len=82
>>> send_msg: type=8, len=53
>>> send_msg: type=9, len=0
Opened '/usr/local/ndt/serverdata/2009/08/29/20090829T07:14:30.977117000Z_10.108.0.15:4255.meta' metadata log file
Successfully returned from run_test() routine
Signal 17 received by process 8856
now = 1251530101 Process started at 1251530070, run time = 31
Select exited with rc = -1
Queue pointer = 8857, testing = 1, waiting = 1, zombie_check = 0
Received SIGCHLD signal for active web100srv process [8856]
wait3() returned 0 for PID=8857
wexitstatus = '0'
Attempting to clean up child 8857, head pid = 8857
Child process 8857 causing head pointer modification
Removing Child from head, decrementing waiting now = 0
Timer not running, waiting for new connection
>>
 
I hope the debugging output helps...
 
thanks and best regards
Christoph Galuschka


From: Richard Carlson [mailto:]
Sent: Fri 8/28/2009 14:25
To: Galuschka Christoph
Cc:
Subject: Re: Error running web100 3.5.0

Hi Chris;

Sorry about that.  There is a bug in the 3.5.0 release.  You can 
download the latest version (3.5.6 which will be posted soon) or you 
can easily patch the 3.5.0 release.  Just edit the src/testoptions.c 
file and go to line 730.  You should find the line /* wait(NULL); */  
- which ofcourse makes this a comment.  Remove the "/*" and "*/" 
char's (so its not a comment) and rebuild/reinstall the package.  This 
should clear out this fault.

Rich

On Aug 27, 2009, at 4:47 AM, wrote:

> Hello,
>
> I've just finished installing ndt-3.5.0 on a fresh SuSE 11.1 System 
> (incl. alle prerequisits; patch for kernel 2.6.27, 
> web100_userland-1.7). Server runs fine and I do get bandwith results.
>
> However, the web100srv produces an error which fails to compelte the 
> test successfully. This is the output from -ddd:
> ANL/Internet2 NDT ver 3.5.0
>        Variables file = /usr/local/ndt/web100_variables
>        log file = /usr/local/ndt/web100srv.log
>        Debug level set to 1
> server ready on port 3001
> web100_init() read 69 variables from file
> Starting test suite:
>> Middlebox test
>> Simple firewall test
>> C2S throughput test
>> S2C throughput test
> <-- Middlebox test -->
>  -- port: 3003
> Sending 1456 Byte packets over the network
> Signal 17 received by process 22352
> <-------------------->
> <-- Simple firewall test -->
>  -- port: 42133
>  -- time: 1
>  -- oport: 2571
> <-------------------------->
> <-- C2S throughput test -->
>  -- port: 3002
> listening for Inet connection on testOptions->c2ssockfd, fd=3
> Sending 'GO' signal, to tell client to head for the next test
> Opening network interface 'eth2' for packet-pair timing
> installing pkt filter for 'host 10.110.109.104 and port 2574'
> Initial pkt src data = "8068484> New packet trace started -- initializing counters
> 365314 kbps outbound
> Signal USR1(10) sent to child [22355]
> Signal 10 received by process 22355
> 03:16:15.649224   03:16:15.649224   128 bytes read '  0 0 84 694 
> 7815 18212 77975 16876 70005 144937 1 1558 232.14 0 0 0 1 0' from 
> monitor pipe
> 128 bytes read '  1 0 0 99 558 1644 45429 40869 16975 3745 1 1 
> 274.82 86 14 109221 0 0' from monitor pipe
> <------------------------->
> <-- S2C throughput test -->
>  -- port: 3003
> waiting for data on testOptions->s2csockfd
> Signal 11 received by process 22355
> Signal 17 received by process 22352
> Opening network interface 'eth2' for packet-pair timing
> installing pkt filter for 'host 10.110.109.104 and port 2580'
> Initial pkt src data = "8068484> Signal 17 received by process 22352
> New packet trace started -- initializing counters
> sent 716955648 bytes to client in 10.00 seconds
> Buffer control counters Total = 87519, new data = "0," Draining Queue 
> = 0
> Signal USR2(12) sent to child [22357]
> Signal 12 received by process 22357
> 03:16:26.019890   03:16:26.019890   Read '  0 0 1 1 5 6 9612 1476 
> 1235 1247 0 4235 454.46 0 0 0 1 0' from monitor pipe
> Read '  0 0 0 3 1179 9323 46700 9154 13887 148207 4687 19061 273.91 
> 10056 242043 102 0 4687' from monitor pipe
> 573470 kbps inbound
> libweb100: warning: accessing depricated variable AckPktsIn
> libweb100: warning: accessing depricated variable AckPktsOut
> Variable 13 (CwndRestores) not found in KIS
> Variable 22 (MaxCaCwnd) not found in KIS
> Variable 30 (MaxSaCwnd) not found in KIS
> Variable 13 (CwndRestores) not found in KIS
> Variable 22 (MaxCaCwnd) not found in KIS
> Variable 30 (MaxSaCwnd) not found in KIS
> Signal 11 received by process 22357
> Signal 17 received by process 22352
> Protocol error!
> S2C throughput test FAILED!
> Client --> Server data detects link = 10 Gigabit Enet
> Client <-- Server Ack's detect link = OC-12
> Server --> Client data detects link = OC-12
> Server <-- Client Ack's detect link = 10 Gigabit Enet
>
> If I'm not mistaking, the 2 lines:
>>>
> libweb100: warning: accessing depricated variable AckPktsIn
> libweb100: warning: accessing depricated variable AckPktsOut
>>>
> probably are the source of the problem.
>
> any ideas what i might have missed?
>
> thanks and best regards
> Christoph

Richard Carlson

1000 Oakbrook Dr
Ann Arbor, MI  48104

P: 734-352-7043
C: 630-251-4572




Archive powered by MHonArc 2.6.16.

Top of Page