output of ./runtests.pl -v -d -k -p 405

test log (text/plain), 13.91 KB, created by Michał Kiedrowicz on 2008-01-02 23:12:17 UTC

********* System characteristics ******** 
* curl 7.17.1 (x86_64-pc-linux-gnu) 
* libcurl/7.17.1 GnuTLS/2.2.0 zlib/1.2.3
* Features: Largefile SSL libz 
* Host: localhost
* System: Linux localhost 2.6.23-tuxonice-r4 #4 SMP PREEMPT Fri Dec 7 15:17:20 CET 2007 x86_64 Intel(R) Core(TM)2 CPU 6300 @ 1.86GHz GenuineIntel GNU/Linux
* Server SSL:     OFF
* libcurl SSL:    ON
* libcurl debug:  OFF
* valgrind:       ON
* HTTP IPv6       OFF
* FTP IPv6        OFF
* HTTP port:      8990
* FTP port:       8992
* FTP port 2:     8995
* TFTP port:      8997
* SCP/SFTP port:  8999
* SOCKS port:     9000
* SSL library:    GnuTLS
* Libtool lib:    OFF
***************************************** 
startnew: perl -I. ./ftpserver.pl --pidfile .ftp.pid -v -s "."  --port 8992 --addr "127.0.0.1"
./server/sockfilt --port 8992 --logfile log/sockctrl.log --pidfile .sockfilt.pid 
OUT: 220-        _   _ ____  _     
OUT: 220-    ___| | | |  _ \| |    
OUT: 220-   / __| | | | |_) | |    
OUT: 220-  | (__| |_| |  _ <| |___ 
OUT: 220    \___|\___/|_| \_\_____|
IN: USER anonymous
IN: PASS [e-mail]
IN: PWD
IN: EPSV
IN: TYPE I
IN: SIZE verifiedserver
IN: RETR verifiedserver
FTPD: We returned proof we are the test server
IN: QUIT
RUN: ../src/curl -m13 --silent -vg "ftp://127.0.0.1:8992/verifiedserver" 2>log/verifyftp
RUN: Verifying our test FTP server took 0 seconds
RUN: FTP server is now running PID 16382
* pid ftp => 16382 16382
test 405...[FTPS operation to FTP port]
../libtool --mode=execute /usr/bin/valgrind --tool=memcheck --leak-check=yes --num-callers=16 --log-file=log/valgrind405 ../src/curl --output log/curl405.out  --include -v --trace-time -k ftps://127.0.0.1:8992/path/to/file/405 >>log/stdout405 2>>log/stderr405
OUT: 220-        _   _ ____  _     
OUT: 220-    ___| | | |  _ \| |    
OUT: 220-   / __| | | | |_) | |    
OUT: 220-  | (__| |_| |  _ <| |___ 
OUT: 220    \___|\___/|_| \_\_____|

curl returned 28, 35
 was expected
 exit FAILED
== Contents of files in the log/ dir after test 405
=== Start of file curl.log
 ../libtool --mode=execute /usr/bin/valgrind --tool=memcheck --leak-check=yes --num-callers=16 --log-file=log/valgrind405 ../src/curl --output log/curl405.out  --include -v --trace-time -k ftps://127.0.0.1:8992/path/to/file/405 >>log/stdout405 2>>log/stderr405
=== End of file curl.log
=== Start of file curlverout.log
 curl 7.17.1 (x86_64-pc-linux-gnu) libcurl/7.17.1 GnuTLS/2.2.0 zlib/1.2.3
 Protocols: tftp ftp telnet dict http file https ftps 
 Features: Largefile SSL libz 
=== End of file curlverout.log
=== Start of file ftpd.log
 23:58:09 FTP server listens on port IPv4/8992
 23:58:09 logged pid 16382 in .ftp.pid
 23:58:09 Awaiting input
 23:58:10 ====> Client connect
 23:58:10 > "220-        _   _ ____  _     "
 23:58:10 > "220-    ___| | | |  _ \| |    "
 23:58:10 > "220-   / __| | | | |_) | |    "
 23:58:10 > "220-  | (__| |_| |  _ <| |___ "
 23:58:10 > "220    \___|\___/|_| \_\_____|"
 23:58:10 < "USER anonymous"
 23:58:10 > "331 We are happy you popped in!"
 23:58:10 < "PASS [e-mail]"
 23:58:10 > "230 Welcome you silly person"
 23:58:10 < "PWD"
 23:58:10 > "257 "/nowhere/anywhere" is current directory"
 23:58:10 < "EPSV"
 23:58:10 Run sockfilt for data on pid 16913
 23:58:10 > "229 Entering Passive Mode (|||50381|)"
 23:58:10 ====> Client DATA connect
 23:58:10 data connection setup on port 50381
 23:58:10 < "TYPE I"
 23:58:10 > "200 I modify TYPE as you wanted"
 23:58:10 < "SIZE verifiedserver"
 23:58:10 > "213 17"
 23:58:10 < "RETR verifiedserver"
 23:58:10 > "150 Binary junk (17 bytes)."
 23:58:10 * disconnect data connection
 23:58:10 =====> Closed data connection
 23:58:10 * quit sockfilt for data (pid 16913)
 23:58:10 > "226 File transfer complete"
 23:58:10 < "QUIT"
 23:58:10 > "221 bye bye baby"
 23:58:10 sockfilt said DISC
 23:58:10 ====> Client disconnected
 23:58:10 Awaiting input
 23:58:12 ====> Client connect
 23:58:12 > "220-        _   _ ____  _     "
 23:58:12 > "220-    ___| | | |  _ \| |    "
 23:58:12 > "220-   / __| | | | |_) | |    "
 23:58:12 > "220-  | (__| |_| |  _ <| |___ "
 23:58:12 > "220    \___|\___/|_| \_\_____|"
 23:58:19 > "500 'OKG|
                      )eRñuÀÚvß}LX¢9GÕ·;$3E92D8f/A5': command not understood."
 23:58:19 ====> Client disconnected
 23:58:19 Awaiting input
 00:03:12 sockfilt said: DISC
 00:03:12 Awaiting input
=== End of file ftpd.log
=== Start of file server.input
 OKG|
     )eR
 ñuÀÚvß}LX
 ¢9GÕ·;$3E92D8f/A5
 
=== End of file server.input
=== Start of file sockctrl.log
 23:58:09.022372 Running IPv4 version
 23:58:09.022657 Listening on port 8992
 23:58:09.022750 Wrote pid 16392 to .sockfilt.pid
 23:58:09.023091 Received PING (on stdin)
 23:58:10.033938 ====> Client connect
 23:58:10.034223 Received DATA (on stdin)
 23:58:10.034258 > 32 bytes data, server => client
 23:58:10.034293 read 32 bytes
 23:58:10.034323 '220-        _   _ ____  _     \r\n'
 23:58:10.034442 Received DATA (on stdin)
 23:58:10.034472 > 32 bytes data, server => client
 23:58:10.034504 read 32 bytes
 23:58:10.034533 '220-    ___| | | |  _ \| |    \r\n'
 23:58:10.034617 Received DATA (on stdin)
 23:58:10.034646 > 32 bytes data, server => client
 23:58:10.034679 read 32 bytes
 23:58:10.034708 '220-   / __| | | | |_) | |    \r\n'
 23:58:10.034794 Received DATA (on stdin)
 23:58:10.034823 > 32 bytes data, server => client
 23:58:10.034855 read 32 bytes
 23:58:10.034883 '220-  | (__| |_| |  _ <| |___ \r\n'
 23:58:10.034963 Received DATA (on stdin)
 23:58:10.034992 > 32 bytes data, server => client
 23:58:10.035023 read 32 bytes
 23:58:10.035052 '220    \___|\___/|_| \_\_____|\r\n'
 23:58:10.035155 < 16 bytes data, client => server
 23:58:10.035187 'USER anonymous\r\n'
 23:58:10.035916 Received DATA (on stdin)
 23:58:10.035964 > 33 bytes data, server => client
 23:58:10.035998 read 33 bytes
 23:58:10.036027 '331 We are happy you popped in!\r\n'
 23:58:10.0361^[[?1;2c^[[?1;2c52 < 22 bytes data, client => server
 23:58:10.036182 'PASS [e-mail]\r\n'
 23:58:10.036441 Received DATA (on stdin)
 23:58:10.036475 > 30 bytes data, server => client
 23:58:10.036508 read 30 bytes
 23:58:10.036537 '230 Welcome you silly person\r\n'
 23:58:10.036632 < 5 bytes data, client => server
 23:58:10.036661 'PWD\r\n'
 23:58:10.036886 Received DATA (on stdin)
 23:58:10.036918 > 46 bytes data, server => client
 23:58:10.036952 read 46 bytes
 23:58:10.036982 '257 "/nowhere/anywhere" is current directory\r\n'
 23:58:10.037433 < 6 bytes data, client => server
 23:58:10.037468 'EPSV\r\n'
 23:58:10.039872 Received DATA (on stdin)
 23:58:10.039932 > 38 bytes data, server => client
 23:58:10.039962 read 38 bytes
 23:58:10.039990 '229 Entering Passive Mode (|||50381|)\n'
 23:58:10.040317 < 8 bytes data, client => server
 23:58:10.040351 'TYPE I\r\n'
 23:58:10.040607 Received DATA (on stdin)
 23:58:10.040641 > 33 bytes data, server => client
 23:58:10.040669 read 33 bytes
 23:58:10.040698 '200 I modify TYPE as you wanted\r\n'
 23:58:10.040798 < 21 bytes data, client => server
 23:58:10.040831 'SIZE verifiedserver\r\n'
 23:58:10.040946 Received DATA (on stdin)
 23:58:10.040980 > 8 bytes data, server => client
 23:58:10.041006 read 8 bytes
 23:58:10.041040 '213 17\r\n'
 23:58:10.041130 < 21 bytes data, client => server
 23:58:10.041168 'RETR verifiedserver\r\n'
 23:58:10.041343 Received DATA (on stdin)
 23:58:10.041386 > 29 bytes data, server => client
 23:58:10.041413 read 29 bytes
 23:58:10.041442 '150 Binary junk (17 bytes).\r\n'
 23:58:10.042041 Received DATA (on stdin)
 23:58:10.042074 > 28 bytes data, server => client
 23:58:10.042107 read 28 bytes
 23:58:10.042136 '226 File transfer complete\r\n'
 23:58:10.085317 < 6 bytes data, client => server
 23:58:10.085379 'QUIT\r\n'
 23:58:10.085726 Received DATA (on stdin)
 23:58:10.085762 > 18 bytes data, server => client
 23:58:10.085797 read 18 bytes
 23:58:10.085826 '221 bye bye baby\r\n'
 23:58:10.085958 ====> Client disconnect
 23:58:12.581970 ====> Client connect
 23:58:12.582440 Received DATA (on stdin)
 23:58:12.582477 > 32 bytes data, server => client
 23:58:12.582504 read 32 bytes
 23:58:12.582533 '220-        _   _ ____  _     \r\n'
 23:58:12.582590 Received DATA (on stdin)
 23:58:12.582620 > 32 bytes data, server => client
 23:58:12.582646 read 32 bytes
 23:58:12.582674 '220-    ___| | | |  _ \| |    \r\n'
 23:58:12.582716 Received DATA (on stdin)
 23:58:12.582745 > 32 bytes data, server => client
 23:58:12.582771 read 32 bytes
 23:58:12.582799 '220-   / __| | | | |_) | |    \r\n'
 23:58:12.582840 Received DATA (on stdin)
 23:58:12.582868 > 32 bytes data, server => client
 23:58:12.582895 read 32 bytes
 23:58:12.582923 '220-  | (__| |_| |  _ <| |___ \r\n'
 23:58:12.582965 Received DATA (on stdin)
 23:58:12.582993 > 32 bytes data, server => client
 23:58:12.583081 read 32 bytes
 23:58:12.583111 '220    \___|\___/|_| \_\_____|\r\n'
 23:58:19.308895 < 84 bytes data, client => server
 23:58:19.308988 '....O...K..G|..)e.R\n...u....v.}LX\n.9G.....;..$.3.E.9.....2.'
 23:58:19.309019 'D.8.....f./.A.5...\n......'
 23:58:19.309371 Received DATA (on stdin)
 23:58:19.309404 > 117 bytes data, server => client
 23:58:19.309430 read 117 bytes
 23:58:19.309461 '500 '....O...K..G|..)e.R\n...u....v.}LX\n.9G.....;..$.3.E.9..'
 23:58:19.309492 '...2.D.8.....f./.A.5...\n......': command not understood.\r\n'
 00:03:12.564001 ====> Client disconnect
=== End of file sockctrl.log
=== Start of file sockdata.log
 23:58:10.039190 Running IPv4 version
 23:58:10.039464 Listening on port 50381
 23:58:10.039572 Wrote pid 16913 to .sockdata.pid
 23:58:10.039609 Received PING (on stdin)
 23:58:10.039761 Received PORT (on stdin)
 23:58:10.040258 ====> Client connect
 23:58:10.041333 Received DATA (on stdin)
 23:58:10.041373 > 17 bytes data, server => client
 23:58:10.041406 read 17 bytes
 23:58:10.041435 'WE ROOLZ: 16382\r\n'
 23:58:10.041564 Received DISC (on stdin)
 23:58:10.041596 ====> Client forcibly disconnected
 23:58:10.041888 Received QUIT (on stdin)
 23:58:10.041918 quits
=== End of file sockdata.log
=== Start of file stderr405
 23:58:12.479527 * About to connect() to 127.0.0.1 port 8992 (#0)
 23:58:12.577246 *   Trying 127.0.0.1... connected
 23:58:12.595566 * Connected to 127.0.0.1 (127.0.0.1) port 8992 (#0)
 23:58:18.994121 * found 100 certificates in /etc/ssl/certs/ca-certificates.crt
 00:03:12.396957 * SSL connection timeout
 00:03:12.406002 * Closing connection #0
 
 curl: (28) SSL connection timeout
=== End of file stderr405
=== Start of file valgrind405
 ==17511== Memcheck, a memory error detector.
 ==17511== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al.
 ==17511== Using LibVEX rev 1804, a library for dynamic binary translation.
 ==17511== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP.
 ==17511== Using valgrind-3.3.0, a dynamic binary instrumentation framework.
 ==17511== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al.
 ==17511== For more details, rerun with: -v
 ==17511== 
 ==17511== My PID = 17511, parent PID = 17509.  Prog and args are:
 ==17511==    /var/tmp/portage/net-misc/curl-7.17.1/work/curl-7.17.1/src/.libs/lt-curl
 ==17511==    --output
 ==17511==    log/curl405.out
 ==17511==    --include
 ==17511==    -v
 ==17511==    --trace-time
 ==17511==    -k
 ==17511==    ftps://127.0.0.1:8992/path/to/file/405
 ==17511== 
 ==17511== 
 ==17511== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 4 from 1)
 ==17511== malloc/free: in use at exit: 5,540 bytes in 46 blocks.
 ==17511== malloc/free: 3,517,335 allocs, 3,517,289 frees, 36,996,166,685 bytes allocated.
 ==17511== For counts of detected errors, rerun with: -v
 ==17511== searching for pointers to 46 not-freed blocks.
 ==17511== checked 109,880 bytes.
 ==17511== 
 ==17511== 2,772 (64 direct, 2,708 indirect) bytes in 2 blocks are definitely lost in loss record 3 of 5
 ==17511==    at 0x4A06E40: malloc (vg_replace_malloc.c:207)
 ==17511==    by 0x339942CC93: _gnutls_hash_init (gnutls_hash_int.c:74)
 ==17511==    by 0x3399429281: gnutls_handshake (gnutls_handshake.c:2105)
 ==17511==    by 0x4C36D2C: handshake (gtls.c:154)
 ==17511==    by 0x4C37486: Curl_gtls_connect (gtls.c:340)
 ==17511==    by 0x4C229DF: Curl_ftp_connect (ftp.c:3097)
 ==17511==    by 0x4C2356C: Curl_protocol_connect (url.c:2759)
 ==17511==    by 0x4C25AE1: Curl_connect (url.c:4250)
 ==17511==    by 0x4C2F9C0: Curl_perform (transfer.c:2333)
 ==17511==    by 0x407956: main (main.c:4417)
 ==17511== 
 ==17511== LEAK SUMMARY:
 ==17511==    definitely lost: 64 bytes in 2 blocks.
 ==17511==    indirectly lost: 2,708 bytes in 6 blocks.
 ==17511==      possibly lost: 0 bytes in 0 blocks.
 ==17511==    still reachable: 2,768 bytes in 38 blocks.
 ==17511==         suppressed: 0 bytes in 0 blocks.
 ==17511== Reachable blocks (those to which a pointer was found) are not shown.
 ==17511== To see them, rerun with: --leak-check=full --show-reachable=yes
=== End of file valgrind405
=== Start of file verifyftp
 * About to connect() to 127.0.0.1 port 8992 (#0)
 *   Trying 127.0.0.1... connected
 * Connected to 127.0.0.1 (127.0.0.1) port 8992 (#0)
 < 220-        _   _ ____  _     
 < 220-    ___| | | |  _ \| |    
 < 220-   / __| | | | |_) | |    
 < 220-  | (__| |_| |  _ <| |___ 
 < 220    \___|\___/|_| \_\_____|
 > USER anonymous
 < 331 We are happy you popped in
 > PASS [e-mail]
 < 230 Welcome you silly person
 > PWD
 < 257 "/nowhere/anywhere" is current directory
 * Entry path is '/nowhere/anywhere'
 > EPSV
 * Connect data stream passively
 < 229 Entering Passive Mode (|||50381|)
 *   Trying 127.0.0.1... connected
 * Connecting to 127.0.0.1 (127.0.0.1) port 50381
 > TYPE I
 < 200 I modify TYPE as you wanted
 > SIZE verifiedserver
 < 213 17
 > RETR verifiedserver
 < 150 Binary junk (17 bytes).
 * Maxdownload = -1
 * Getting file with size: 17
 { [data not shown]
 * Remembering we are in dir ""
 < 226 File transfer complete
 * Connection #0 to host 127.0.0.1 left intact
 > QUIT
 < 221 bye bye baby
 * Closing connection #0
=== End of file verifyftp

 - abort tests
* kill pid for ftp => 16382
RUN: Test server pid 16382 signalled to die
TESTDONE: 0 tests out of 1 reported OK: 0%
TESTFAIL: These test cases failed: 405 
TESTDONE: 1 tests were considered during 304 seconds.