NDT-DEV email list created

[Tom Throckmorton <>]

On Tue, Aug 14, 2012 at 1:39 PM, Kavitha Kumar 
<>
 wrote:
> Hi Tom,
>
>   Would you pls replace your src/ndt_odbc.c with the file at 
> http://patdev2.internet2.edu/NDT_TAR/ndt_odbc.c, run your server with 
> -ddddddd, and send me your web100srv.log file ?

Kavitha, thanks for you help!

Attached is the web100srv and debug output (db pw sanitized) from our
offline test scenario yesterday in which the insert failed.

-tt


> ----- Original Message -----
>> From: "Tom Throckmorton" 
>> <>
>> To: "Kavitha Kumar" 
>> <>
>> Cc: 
>> 
>> Sent: Monday, August 13, 2012 6:09:28 PM
>> Subject: Re: NDT 3.6.5.2 + ODBC
>>
>> On 8/13/12 5:40 PM, Tom Throckmorton wrote:
>> > Hi Kavitha,
>> >
>> > Rather than hijack the previous thread, I've started a new one -
>> > comments below...
>> >
>> > On 8/13/12 1:46 PM, Kavitha Kumar wrote:
>> >> Hi all,
>> >>
>> >>   The RPMS/source distribution of 3.6.5.2 are available here:
>> >>   http://patdev2.internet2.edu/
>> >>
>> >> It would be great if I could get feedback on how these build on
>> >> your environment and or/run after installation.
>> >
>> > FWIW, that version rebuilds cleanly for me in mock.  The client
>> > works
>> > with servers of various releases, and the server appears to work
>> > fine
>> > (tests complete, no hanging, etc.), however, I did notice db
>> > logging is
>> > no longer working.  It appears to have broken somewhere between
>> > 3.5.6
>> > and this release, though I don't have any intermediate builds handy
>> > to
>> > help narrow it down further.  If you need, I can try to do that.
>>
>> To hopefully save some time, I rebuilt 3.6.4 just now, and db logging
>> works there, so the problem occurred somewhere between 3.6.4 and
>> 3.6.5.x
>>
>> -tt
>>
>> >
>> > The db appears to initialize correctly at startup:
>> >
>> >> throck@rpop-probe-test%
>> >>  sudo /usr/sbin/web100srv -a --debug --ipv4
>> >> --syslog -l /var/log/ndt/web100srv.log --enableDBlogging --dbDSN
>> >> ndt_data --dbUID ndt --dbPWD ********
>> >> ----DataDirName=/usr/ndt/serverdata/
>> >> ANL/Internet2 NDT ver 3.6.5.2
>> >>    Variables file = /usr/ndt/web100_variables
>> >>    log file = /var/log/ndt/web100srv.log
>> >>    Admin file = /usr/ndt/admin.html
>> >>    Syslog facility = default (128)
>> >>    Debug level set to 1
>> >> Initializing DB with DSN='ndt_data', UID='ndt', PWD=yes
>> >> ...
>> >
>> > However, during a test, it fails to update the db:
>> >
>> >> ...
>> >> --Is congested? 1
>> >>   Failed to insert test results into the table
>> >>  Continuing without DB logging
>> >> Updating admin_view variables: Total count = 11
>> >> ....
>> >
>> > I do use the db logging feature and find it useful - any ideas
>> > why/where
>> > this stopped working?  Let me know what additional info you need to
>> > help
>> > track it down.
>> >
>> > Cheers,
>> >
>> > -tt
>> >
>> >
>>
>>
>> --
>> Tom Throckmorton
>> MCNC
>> 919.248.1448
>>
>> "Connecting North Carolina's future today"
>>



-- 
Tom Throckmorton
MCNC
919.248.1448

"Connecting North Carolina's future today"
----DataDirName=/usr/ndt/serverdata/
ANL/Internet2 NDT ver 3.6.5.2
        Variables file = /usr/ndt/web100_variables
        log file = /var/log/ndt/web100srv.log
        Admin file = /usr/ndt/admin.html
        Syslog facility = default (128)
        Debug level set to 7
Initializing DB with DSN='ndt_data', UID='ndt', PWD=yes
  Connected
  Returned connection string was:
        DATABASE=ndt_data;DESCRIPTION=NDT test 
results;DSN=ndt_data;OPTION=4718596;PWD=******;PORT=3306;SERVER=localhost;UID=ndt;
Fetched SQLNumResults:5

Send buffer initialized to 65536, Receive buffer initialized to 87380
server ready on port 3001
web100_init() read 69 variables from file
Web100 variables line received

-- Average round trip time= SumRTT (1933673) over countRTT (149953)=0.012895
--packets out of order: 0.095205
--max_theoretical_thruput: inf. From 1448,0.000000,0.000014
--Total test time: 208383+527667+9357254=10093304 
--Send limited time: 208383 over 10093304=0.020646 
--Send limited time: 527667 over 10093304=0.052279 
--Send limited time: 9357254 over 10093304=0.927075 
Initial counter Values Totalcnt = 0, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 1, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1581497) over countRTT (120449)=0.013130
--packets out of order: 0.116268
--max_theoretical_thruput: nan. From 1448,0.000000,0.000306
--Total test time: 147130+1461833+8484384=10093347 
--Send limited time: 147130 over 10093347=nan 
--Send limited time: 1461833 over 10093347=nan 
--Send limited time: 8484384 over 10093347=nan 
Initial counter Values Totalcnt = 1, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 2, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (4491184) over countRTT (313742)=0.014315
--packets out of order: 0.095224
--max_theoretical_thruput: nan. From 1448,0.000000,0.000231
--Total test time: 22932+1181402+8894060=10098394 
--Send limited time: 22932 over 10098394=nan 
--Send limited time: 1181402 over 10098394=nan 
--Send limited time: 8894060 over 10098394=nan 
Initial counter Values Totalcnt = 2, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 3, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 3, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1836695) over countRTT (142893)=0.012854
--packets out of order: 0.100794
--max_theoretical_thruput: nan. From 1448,0.000000,0.000012
--Total test time: 211833+503515+9378913=10094261 
--Send limited time: 211833 over 10094261=nan 
--Send limited time: 503515 over 10094261=nan 
--Send limited time: 9378913 over 10094261=nan 
Initial counter Values Totalcnt = 3, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 4, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1465095) over countRTT (112750)=0.012994
--packets out of order: 0.120716
--max_theoretical_thruput: nan. From 1448,0.000000,0.000013
--Total test time: 36758+759961+9307572=10104291 
--Send limited time: 36758 over 10104291=nan 
--Send limited time: 759961 over 10104291=nan 
--Send limited time: 9307572 over 10104291=nan 
Initial counter Values Totalcnt = 4, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 5, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 5, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (4165834) over countRTT (310005)=0.013438
--packets out of order: 0.082668
--max_theoretical_thruput: nan. From 1448,0.000000,0.000023
--Total test time: 213846+711607+9179871=10105324 
--Send limited time: 213846 over 10105324=nan 
--Send limited time: 711607 over 10105324=nan 
--Send limited time: 9179871 over 10105324=nan 
Initial counter Values Totalcnt = 5, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 6, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 6, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1767341) over countRTT (134056)=0.013184
--packets out of order: 0.106818
--max_theoretical_thruput: nan. From 1448,0.000000,0.000011
--Total test time: 30285+822916+9242057=10095258 
--Send limited time: 30285 over 10095258=nan 
--Send limited time: 822916 over 10095258=nan 
--Send limited time: 9242057 over 10095258=nan 
Initial counter Values Totalcnt = 6, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 7, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 7, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1508226) over countRTT (129863)=0.011614
--packets out of order: 0.104916
--max_theoretical_thruput: nan. From 1448,0.000000,0.000013
--Total test time: 22040+1267260+8801760=10091060 
--Send limited time: 22040 over 10091060=nan 
--Send limited time: 1267260 over 10091060=nan 
--Send limited time: 8801760 over 10091060=nan 
Initial counter Values Totalcnt = 7, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 8, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 8, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (3851828) over countRTT (279569)=0.013778
--packets out of order: 0.102420
--max_theoretical_thruput: nan. From 1448,0.000000,0.000101
--Total test time: 278075+1516440+8313784=10108299 
--Send limited time: 278075 over 10108299=nan 
--Send limited time: 1516440 over 10108299=nan 
--Send limited time: 8313784 over 10108299=nan 
Initial counter Values Totalcnt = 8, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 9, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 9, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (1736917) over countRTT (136799)=0.012697
--packets out of order: 0.121785
--max_theoretical_thruput: nan. From 1448,0.000000,0.000016
--Total test time: 193654+539971+9355795=10089420 
--Send limited time: 193654 over 10089420=nan 
--Send limited time: 539971 over 10089420=nan 
--Send limited time: 9355795 over 10089420=nan 
Initial counter Values Totalcnt = 9, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 10, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 10, 0, 0, 0, 0, 0, 0, 0, 0]
Web100 variables line received

-- Average round trip time= SumRTT (3908227) over countRTT (296169)=0.013196
--packets out of order: 0.089214
--max_theoretical_thruput: nan. From 1448,0.000000,0.000022
--Total test time: 19989+1569937+8523353=10113279 
--Send limited time: 19989 over 10113279=nan 
--Send limited time: 1569937 over 10113279=nan 
--Send limited time: 8523353 over 10113279=nan 
Initial counter Values Totalcnt = 10, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 11, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 11, 0, 0, 0, 0, 0, 0, 0, 0]
Signal 17 received by process 12089
Signal 17 (SIGCHLD) received - completed tests = 1
successfully locked '/tmp/view.string' for updating
sending 
'778472,599143,669870,496783,11,0,0,0,0,0,0,0,0,0,11,0,0,0,0,0,0,0,0,Aug 14 
19:05:36,Aug 14 19:28:18' to tmp file
NDT server (v3.6.5.2) process [12089] started at Aug 14 15:38:53
Generated iflist with device=eth0 and if_speed=7
Generated iflist with device=eth1 and if_speed=7
nothing in queue
Timer not running, waiting for new connection
New connection received, waiting for accept() to complete
Select() found 1 clients ready, highest fd=5
New connection received from 0x86e7908 [128.109.7.241] sockfd=9.
--current process name = connect for 1

--current process status = started for 1

Protocol logging is not enabled
Child thinks pipe() returned fd0=10, fd1=11 for pid=0
Parent process spawned child = 12093
Parent thinks pipe() returned fd0=10, fd1=11
Protocol logging is not enabled
Client connect received from :IP 128.109.7.241 to some server on socket 9
creating new child - semaphore locked
Free'd ndtq semaphore lock - 1
initialize_tests returned old/new client = 0, test_suite = 1 8 2 4
Incrementing waiting variable now = 1
Line just before ChldRdy: label, did't get here via the goto statement!
___-------______  client process is ready for testing!
Telling client 12093 testing will begin now
sending 'GO' signal to client msg='go 15 1 8 2 4'
Protocol logging is not enabled
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Child 12093 received 'go 15 1 8 2 4' from parent
Got 'go' signal from parent, ready to start testing 12093
extracting test_suite ' 1 8 2 4' and t_opts 'f' from buff 'go 15 1 8 2 4'
setting master alarm() to 120 seconds, tests must start (complete?) before 
this timer expires
Valid test sequence requested, run test for client=12093
Remote host= 128.109.7.241
Child process 12093 started
Protocol logging is not enabled
run_test() routine, asking for test_suite =  1 8 2 4
Protocol logging is not enabled
Starting test suite:
 > Middlebox test
 > Simple firewall test
 > C2S throughput test
 > S2C throughput test
Starting middlebox test
 <-- 12093 - Middlebox test -->
Protocol logging is not enabled

Send buffer initialized to 65536, Receive buffer initialized to 87380
  -- port: 3003
Protocol logging is not enabled
--current process name = connect for 1

--current process status = started for 1

Protocol logging is not enabled
Looking for Web100 data on socketid 10
Server: 128.109.178.47;3003 Client: 128.109.7.241;33520 1444;8;8;
Sending 1444 Byte packets over the network, and data=8;
Setting Cwnd Limit to 2888 octets
Signal 17 received by process 12093
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Finished with web100_middlebox() routine snap-0x86cf1c8, sndbuff=86eabe00x
Protocol logging is not enabled
Protocol logging is not enabled
CWND limited throughput = 2478 kbps (2478)
Protocol logging is not enabled
 <--------- 12093 ----------->
Protocol logging is not enabled
Starting simple firewall test
 <-- 12093 - Simple firewall test -->
Protocol logging is not enabled

Send buffer initialized to 65536, Receive buffer initialized to 87380
  -- port: 34177
  -- SFW time: 1
Protocol logging is not enabled
Protocol logging is not enabled
  -- oport: 34504
Protocol logging is not enabled

Send buffer initialized to 65536, Receive buffer initialized to 87380
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Simple firewall test: no connection for 1 seconds
Protocol logging is not enabled
SFW - SIGALRM was caught
SFW - SIGALRM was caught
Unable to create connect socket.
Protocol logging is not enabled
Protocol logging is not enabled
 <-------------------------->
Starting c2s throughput test
 <-- 12093 - C2S throughput test -->
Protocol logging is not enabled

Send buffer initialized to 65536, Receive buffer initialized to 87380
  -- port: 3002
listening for Inet connection on testOptions->c2ssockfd, fd=5
Sending 'GO' signal, to tell client 12093 to head for the next test
Protocol logging is not enabled
child 12093 - sent c2s prepare to client
accept() for 12093 completed
--current process name = connect for 1

--current process status = started for 1

Protocol logging is not enabled
child 12093 - c2s ready for test with fd=11
C2S test Child 12093 thinks pipe() returned fd0=12, fd1=13
C2S test calling init_pkttrace() with pd=0xbfa6a208
Unknown address family=17 found
IPv4 interface found address=128.109.178.47
IPv4 address match, setting device to 'eth0'
Opening network interface 'eth0' for packet-pair timing
pcap_open_live() returned pointer 0x86ec5e0
installing pkt filter for 'host 128.109.7.241 and port 48659'
Initial pkt src data = 8073c44
--tracefile after packet_trace 
C2S test Parent thinks pipe() returned fd0=12, fd1=13
DirNAME=/usr/ndt/serverdata/
end named_log_create 
/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:48659.c2s_snaplog
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Protocol logging is not enabled
New IPv4 packet trace started -- initializing counters
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
517193 kbps outbound for child 12093
Protocol logging is not enabled
Signal USR1(10) sent to child [12109]
Signal 10 received by process 12109
DEBUG, caught SIGUSR1, setting sig1 flag to force exit
Received SIGUSRx signal terminating data collection loop for pid=12109
Sending pkt-pair data back to parent on pipe 12, 13
fwd.saddr = f1076d80:48659, rev.saddr = 2fb26d80:3002
13:39:05.840533   128.109.7.241:48659 --> 128.109.178.47:3002 Collected 
pkt-pair data max = 259496
wrote 76 bytes: link counters are '  1 0 23 1034 2701 1026 39096 10992 259496 
135066 171 356 277.91 0 0 0 1 0 7'7#$#$#$#$ pcap routine says window 
increases = 0, decreases = 0, no change = 0
13:39:05.840533   128.109.178.47:3002 --> 128.109.7.241:48659 Collected 
pkt-pair data max = 94481
wrote 87 bytes: link counters are '  0 0 7 473 1518 2263 33765 2515 94481 
71186 23510 249 nan 18972 15227 195768 0 23510 7'
#$#$#$#$ pcap routine says window increases = 18972, decreases = 15227, no 
change = 195768
Protocol logging is not enabled
 <----------- 12093 -------------->
Protocol logging is not enabled
Starting s2c throughput test
 <-- 12093 - S2C throughput test -->
Protocol logging is not enabled

Send buffer initialized to 65536, Receive buffer initialized to 87380
  -- s2c 12093 port: 3003
Protocol logging is not enabled
12093 waiting for data on testOptions->s2csockfd
accept() for 12093 completed
--current process name = connect for 1

--current process status = started for 1

Protocol logging is not enabled
S2C child 12093, ready to fork()
S2C test Child thinks pipe() returned fd0=12, fd1=13
Finished reading pkt-pair data from network, process 12109 should terminate 
now
pcap_loop exited recvfrom: Bad file descriptor
Pkt-Pair data collection ended, waiting for signal to terminate process
Signal 17 received by process 12093
Unknown address family=17 found
IPv4 interface found address=128.109.178.47
IPv4 address match, setting device to 'eth0'
Opening network interface 'eth0' for packet-pair timing
pcap_open_live() returned pointer 0x86ecb60
installing pkt filter for 'host 128.109.7.241 and port 33523'
Initial pkt src data = 8073c44
DirNAME=/usr/ndt/serverdata/
end named_log_create 
/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:33523.s2c_snaplog
Signal 17 received by process 12093
Protocol logging is not enabled
S2C child 12093 beginning test
New IPv4 packet trace started -- initializing counters
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Waiting for new connection, timer running
S2C child 12093 finished test
Protocol logging is not enabled
sent 781115392 bytes to client in 10.00 seconds
Buffer control counters Total = 95351, new data = 0, Draining Queue = 0
Signal USR2(12) sent to child [12111]
Signal 12 received by process 12111
DEBUG, caught SIGUSR2, setting sig2 flag to force exit
Received SIGUSRx signal terminating data collection loop for pid=12111
Sending pkt-pair data back to parent on pipe 12, 13
fwd.saddr = 2fb26d80:3003, rev.saddr = f1076d80:33523
13:39:16.072232   128.109.178.47:3003 --> 128.109.7.241:33523 Collected 
pkt-pair data max = 9133
wrote 62 bytes: link counters are '  0 0 6 19 59 117 3800 9133 3682 976 16 
627 801.71 0 0 0 0 0 7'
#$#$#$#$ pcap routine says window increases = 0, decreases = 0, no change = 0
62 bytes read '  0 0 6 19 59 117 3800 9133 3682 976 16 627 801.71 0 0 0 0 0 
7' from S2C monitor pipe
13:39:16.072232   128.109.7.241:33523 --> 128.109.178.47:3003 Collected 
pkt-pair data max = 54801
wrote 87 bytes: link counters are '  0 0 9 156 605 910 54801 17573 11528 
38073 9387 688 1061.46 52708 41510 39512 0 9387 7'
#$#$#$#$ pcap routine says window increases = 52708, decreases = 41510, no 
change = 39512
87 bytes read '  0 0 9 156 605 910 54801 17573 11528 38073 9387 688 1061.46 
52708 41510 39512 0 9387 7' from S2C monitor pipe
624856 kbps inbound pid-12111
S2C-Send web100 data vars to client pid=12111
libweb100: warning: accessing depricated variable AckPktsIn
libweb100: warning: accessing depricated variable AckPktsOut
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
S2C test - Send web100 data to client pid=12093
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
S2C test - Send web100 data to client pid=12093
S2CSPD reception starts
Finished reading pkt-pair data from network, process 12111 should terminate 
now
pcap_loop exited recvfrom: Bad file descriptor
Pkt-Pair data collection ended, waiting for signal to terminate process
Protocol logging is not enabled
S2CSPD from client 621905.000000
Protocol logging is not enabled
 <------------ 12093 ------------->
Protocol logging is not enabled
Starting META test
Finished testing C2S = 517.19 Mbps, S2C = 621.90 Mbps
 **First ele: spd=  1 0 23 1034 2701 1026 39096 10992 259496 135066 171 356 
277.91 0 0 0 1 0 7, runave=277.910004
spds[0] = '  1 0 23 1034 2701 1026 39096 10992 259496 135066 171 356 277.91 0 
0 0 1 0 7' max=39096 [71.25%]

Client --> Server data detects link = OC-12
 **First ele: spd=  0 0 7 473 1518 2263 33765 2515 94481 71186 23510 249 nan 
18972 15227 195768 0 23510 7, runave=nan
spds[1] = '  0 0 7 473 1518 2263 33765 2515 94481 71186 23510 249 nan 18972 
15227 195768 0 23510 7' max=33765 [83.29%]

Client <-- Server Ack's detect link = OC-12
 **First ele: spd=  0 0 6 19 59 117 3800 9133 3682 976 16 627 801.71 0 0 0 0 
0 7, runave=801.710022
spds[2] = '  0 0 6 19 59 117 3800 9133 3682 976 16 627 801.71 0 0 0 0 0 7' 
max=9133 [69.54%]

Server --> Client data detects link = Gigabit Ethernet
 **First ele: spd=  0 0 9 156 605 910 54801 17573 11528 38073 9387 688 
1061.46 52708 41510 39512 0 9387 7, runave=1061.459961
spds[3] = '  0 0 9 156 605 910 54801 17573 11528 38073 9387 688 1061.46 52708 
41510 39512 0 9387 7' max=54801 [74.00%]

Server <-- Client Ack's detect link = OC-12
-- Average round trip time= SumRTT (1550530) over countRTT (124399)=0.012464
--packetloss=8 over 538072=0.000015. Link spd=6
--packets out of order: 0.078106
--max_theoretical_thruput: 229.863785. From 1448,0.012464,0.000015
--window sizes: SndWinScale= 8, RcvwinScale=8, MaxRwinRcvd=6291456, 
maxCwnd=2434088,rwin=48.000000, swin=64.000000, cwin=18.570618
--Total test time: 187812+417652+9486872=10092336 
--Send limited time: 187812 over 10092336=0.018609 
--Send limited time: 417652 over 10092336=0.041383 
--Send limited time: 9486872 over 10092336=0.940008 
--RTOIdle:0.021200
--Actual observed throughput: 618.109533 
--Total wait time: 0.212000 
CWND limited test = 2478.00 while unlimited = 621905.00
Better throughput without CWND limits - normal operation
--duplexmismatch?: 0 
--internal duplexmismatch?: 0 
--faulty hardware?: 0 
--Is ethernet?: 0 
--Is wireless?: 0 
--Is DSL/Cable?: 0 
--Is Half_duplex detected? 0 
--Is congested? 1 
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
Protocol logging is not enabled
extracting hostname rpop-probe-ash.ncren.net
DirNAME=/usr/ndt/serverdata/
end named_log_create 
/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:33520.meta
Should compress snaplog and tcpdump files compress=1
Compression is enabled, compress all files in 
'/usr/ndt/serverdata//2012/08/14' basedir
Zlib compression disabled, log files will not be compressed in 
/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:33520.meta
Opened 
'/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:33520.meta'
 metadata log file
Trying to insert data using the statement:INSERT INTO ndt_test_results VALUES 
('  1 0 23 1034 2701 1026 39096 10992 259496 135066 171 356 277.91 0 0 0 1 0 
7','  0 0 7 473 1518 2263 33765 2515 94481 71186 23510 249 nan 18972 15227 
195768 0 23510 7','  0 0 6 19 59 117 3800 9133 3682 976 16 627 801.71 0 0 0 0 
0 7','  0 0 9 156 605 910 54801 17573 11528 38073 9387 688 1061.46 52708 
41510 39512 0 9387 
7',277.910004,nan,801.710022,1061.459961,'','/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:33523.s2c_snaplog','/usr/ndt/serverdata//2012/08/14/20120814T19:38:56.481561000Z_128.109.7.241:48659.c2s_snaplog','128.109.7.241',38446,'Aug
 14 
19:38:56','128.109.7.241',2478,621905,517193,1,1550530,124399,1513,7,538072,0,1448,10584,135508,6291456,8388608,2434088,187812,417652,9486872,779771136,122,151,40,2444224,212,6291456,0,0,0,0,1,6,6,7,6,8,538072,9,8,22,0,0,33,222,0,5,0,0,0,2325728,-1,2309560,1);
  Failed to insert test results into the table
 Continuing without DB logging

The driver reported the following diagnostics whilst running SQLExecDirect:

client_IP=128.109.7.241,c2s_spd=517193,s2c_spd=621905,Timeouts=1,SumRTT=1550530,CountRTT=124399,PktsRetrans=1513,FastRetran=7,DataPktsOut=538072,AckPktsOut=0,CurrentMSS=1448,DupAcksIn=10584,AckPktsIn=135508,MaxRwinRcvd=6291456,Sndbuf=8388608,MaxCwnd=2434088,SndLimTimeRwin=187812,SndLimTimeCwnd=417652,SndLimTimeSender=9486872,DataBytesOut=779771136,SndLimTransRwin=122,SndLimTransCwnd=151,SndLimTransSender=40,MaxSsthresh=2444224,CurrentRTO=212,CurrentRwinRcvd=6291456,link=0,mismatch=0,bad_cable=0,half_duplex=0,congestion=1,c2s_linkspeed_data=6,c2sack=6,s2cdata=7,s2cack=6,CongestionSignals=8,PktsOut=538072,MinRTT=9,RcvWinScale=8

Updating admin_view variables: Total count = 11
-- Average round trip time= SumRTT (1550530) over countRTT (124399)=0.012464
--packets out of order: 0.078106
--max_theoretical_thruput: inf. From 1448,0.000000,0.000015
--Total test time: 187812+417652+9486872=10092336 
--Send limited time: 187812 over 10092336=0.018609 
--Send limited time: 417652 over 10092336=nan 
--Send limited time: 9486872 over 10092336=nan 
Initial counter Values Totalcnt = 11, Total Mismatch = 0, Total Bad Cables = 0
Updated counter values Totalcnt = 12, Total Mismatch = 0, Total Bad Cables = 0
Individual counts = [0, 0, 0, 0, 0, 0, 0, 12, 0, 0, 0, 0, 0, 0, 0, 0]
Signal 17 received by process 12093
successfully locked '/tmp/view.string' for updating
sending 
'778472,517193,669870,496783,12,0,0,0,0,0,0,0,0,0,12,0,0,0,0,0,0,0,0,Aug 14 
19:05:36,Aug 14 19:38:56' to tmp file
Successfully returned from run_test() routine
remove pkt-pair children c2s=12109, s2c=12111
Processing SIGCHLD signal for active web100srv process [12109], sig17=0
wait4() returned 0 for PID=12109
wexitstatus = '0'
Processing SIGCHLD signal for active web100srv process [12111], sig17=0
wait4() returned 0 for PID=0
wexitstatus = '0'
Signal 17 received by process 12089
Signal 17 (SIGCHLD) received - completed tests = 1
Timer expired while waiting for a new connection
Queue pointer=12093, testing=1, waiting=1, mclients=0, zombie_check=0
Handle pending SIGCHLD signal, count=1
Processing SIGCHLD signal for active web100srv process [0], sig17=1
wait3() returned status=0 for PID=12093
wexitstatus = '0'
child_sig() called pid=0, wait returned child=12093 - status=0
checking for pktpair timing children, skip them
        Looking for 12093, curent queue Child 12093, host: 128.109.7.241 
[128.109.7.241], next=0x0
Main test process 12093 terminated, remove from queue
Attempting to clean up child 12093, head pid = 12093
Walkingqueue
        Child 12093, host: 128.109.7.241 [128.109.7.241], next=0x0
Child process 12093 causing head pointer modification, semaphore locked
modifying queue child_proc1=0x86cee68, head_ptr=0x86cee68
free child_proc1=0x86cee68
Removing Child from head, decremented waiting/mclients 0/0
Free'd ndtq semaphore lock - 3
Timer not running, waiting for new connection
S2C test ended, why is timer still running?
Signal 2 received by process 12089

Attachment: web100srv-2012-08-14_15.38.53.log
Description: Binary data