[tor-bugs] #5619 [Obfsproxy]: obfsproxy: test suite failure (EOF)

Tor Bug Tracker & Wiki torproject-admin at torproject.org
Fri Apr 13 15:04:41 UTC 2012


#5619: obfsproxy: test suite failure (EOF)
-----------------------+----------------------------------------------------
 Reporter:  asn        |          Owner:  asn
     Type:  defect     |         Status:  new
 Priority:  normal     |      Milestone:     
Component:  Obfsproxy  |        Version:     
 Keywords:             |         Parent:     
   Points:             |   Actualpoints:     
-----------------------+----------------------------------------------------
 weasel encountered the following two test suite failures:

 {{{
 ======================================================================
 FAIL: test_direct_transfer (__main__.DirectObfs2)
 ----------------------------------------------------------------------
 Traceback (most recent call last):
   File "./tester.py", line 195, in test_direct_transfer
     self.fail("\n" + report)
 AssertionError:
 errors in transfer:
 --- expected
 +++ received
 @@ -1,39 +1 @@
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.

 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -
 -    In obfuscatory age geeky warfare did I wage
 -      For hiding bits from nasty censors\' sight
 -    I was hacker to my set in that dim dark age of net
 -      And I hacked from noon till three or four at night
 -
 -    Then a rival from Helsinki said my protocol was dinky
 -      So I flamed him with a condescending laugh,
 -    Saying his designs for stego might as well be made of lego
 -      And that my bikeshed was prettier by half.
 -
 -    But Claude Shannon saw my shame. From his noiseless channel came
 -       A message sent with not a wasted byte
 -    "There are nine and sixty ways to disguise communiques
 -       And RATHER MORE THAN ONE OF THEM IS RIGHT"
 -
 -\t\t    (apologies to Rudyard Kipling.)
 -
 obfsproxy stderr:
 | 2012-04-13 07:56:52 [notice] Starting (git-8cf684e052cf290e).
 | 2012-04-13 07:56:52 [debug] Configuration 1: obfs2 --dest=127.0.0.1:5001
 server 127.0.0.1:5000
 | 2012-04-13 07:56:52 [debug] obfs2: Parsed options nicely!
 | 2012-04-13 07:56:52 [debug] Configuration 2: obfs2 --dest=127.0.0.1:5000
 client 127.0.0.1:4999
 | 2012-04-13 07:56:52 [debug] obfs2: Parsed options nicely!
 | 2012-04-13 07:56:52 [debug] Now listening on 127.0.0.1:5000 for protocol
 obfs2.
 | 2012-04-13 07:56:52 [debug] Now listening on 127.0.0.1:4999 for protocol
 obfs2.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: new connection from [scrubbed]
 (1 total)
 | 2012-04-13 07:56:52 [debug] [scrubbed]: simple client connection
 | 2012-04-13 07:56:52 [info] [scrubbed] (obfs2): Successful outbound
 connection to '[scrubbed]'.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: setup complete
 | 2012-04-13 07:56:52 [debug] [scrubbed]: new connection from [scrubbed]
 (3 total)
 | 2012-04-13 07:56:52 [debug] [scrubbed]: server connection
 | 2012-04-13 07:56:52 [info] [scrubbed] (obfs2): Successful outbound
 connection to '[scrubbed]'.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: setup complete
 | 2012-04-13 07:56:52 [debug] [scrubbed]: pending_conn_cb
 | 2012-04-13 07:56:52 [debug] [scrubbed]: Successful connection
 | 2012-04-13 07:56:52 [debug] obfs2_handshake: initiator queued 2587 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: pending_conn_cb
 | 2012-04-13 07:56:52 [debug] [scrubbed]: Successful connection
 | 2012-04-13 07:56:52 [debug] obfs2_handshake: responder queued 432 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: upstream_read_cb, 1666 bytes
 available
 | 2012-04-13 07:56:52 [debug] obfs2_send: handshake incomplete, queueing
 1666 bytes.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: transmitted 0 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: downstream_read_cb, 2587 bytes
 available
 | 2012-04-13 07:56:52 [debug] obfs2_recv: received key, expecting 2563
 bytes of padding
 | 2012-04-13 07:56:52 [debug] obfs2_recv: consumed 2563 bytes padding, 0
 still to come
 | 2012-04-13 07:56:52 [debug] obfs2_recv: Processing 0 bytes application
 data
 | 2012-04-13 07:56:52 [debug] [scrubbed]: forwarded 0 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: downstream_read_cb, 432 bytes
 available
 | 2012-04-13 07:56:52 [debug] obfs2_recv: received key, expecting 408
 bytes of padding
 | 2012-04-13 07:56:52 [debug] obfs2_recv: consumed 408 bytes padding, 0
 still to come
 | 2012-04-13 07:56:52 [debug] obfs2_recv: Processing 0 bytes application
 data
 | 2012-04-13 07:56:52 [debug] [scrubbed]: forwarded 0 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: reply of 0 bytes
 | 2012-04-13 07:56:52 [debug] obfs2_send: transmitting 1666 bytes
 previously queued.
 | 2012-04-13 07:56:52 [debug] obfs2_crypt_and_transmit: Processed 1024
 bytes.
 | 2012-04-13 07:56:52 [debug] obfs2_crypt_and_transmit: Processed 642
 bytes.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: transmitted 1666 bytes
 | 2012-04-13 07:56:52 [debug] [scrubbed]: downstream_read_cb, 1666 bytes
 available
 | 2012-04-13 07:56:52 [debug] obfs2_recv: Processing 1666 bytes
 application data
 | 2012-04-13 07:56:52 [debug] obfs2_crypt_and_transmit: Processed 1024
 bytes.
 | 2012-04-13 07:56:52 [debug] obfs2_crypt_and_transmit: Processed 642
 bytes.
 | 2012-04-13 07:56:52 [debug] [scrubbed]: forwarded 1666 bytes
 | 2012-04-13 07:56:53 [debug] error_cb for [scrubbed]: what=0x0011
 | 2012-04-13 07:56:53 [info] EOF from [scrubbed]
 | 2012-04-13 07:56:53 [debug] error_or_eof for [scrubbed]
 | 2012-04-13 07:56:53 [debug] Closing connection with [scrubbed]; 3
 remaining
 | 2012-04-13 07:56:53 [debug] Closing connection with [scrubbed]; 2
 remaining
 | 2012-04-13 07:56:53 [debug] error_cb for [scrubbed]: what=0x0011
 | 2012-04-13 07:56:53 [info] EOF from [scrubbed]
 | 2012-04-13 07:56:53 [debug] error_or_eof for [scrubbed]
 | 2012-04-13 07:56:53 [debug] Closing connection with [scrubbed]; 1
 remaining
 | 2012-04-13 07:56:53 [debug] Closing connection with [scrubbed]; 0
 remaining
 | 2012-04-13 07:56:53 [info] Closing all listeners.
 | 2012-04-13 07:56:53 [notice] Got SIGINT. Preparing shutdown.
 | 2012-04-13 07:56:53 [debug] Beginning normal shutdown.
 | 2012-04-13 07:56:53 [debug] Finishing shutdown.
 | 2012-04-13 07:56:53 [notice] Exiting.
 }}}

 {{{
 ======================================================================
 FAIL: test_socks5_transfer (__main__.SocksDummy)
 ----------------------------------------------------------------------
 Traceback (most recent call last):
   File "./tester.py", line 302, in test_socks5_transfer
     ( (5, 0, 0, 1, 127, 0, 0, 1, SERVER_PORT), "!8BH" ) ])
   File "./tester.py", line 288, in socksTest
     self.fail("\n" + report)
 AssertionError:
 errors in transfer:
 --- expected
 +++ received
 @@ -1,39 +1 @@
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.
 -THIS IS A TEST FILE. IT\'S USED BY THE INTEGRATION TESTS.

 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -"Can entropy ever be reversed?"
 -"THERE IS AS YET INSUFFICIENT DATA FOR A MEANINGFUL ANSWER."
 -
 -    In obfuscatory age geeky warfare did I wage
 -      For hiding bits from nasty censors\' sight
 -    I was hacker to my set in that dim dark age of net
 -      And I hacked from noon till three or four at night
 -
 -    Then a rival from Helsinki said my protocol was dinky
 -      So I flamed him with a condescending laugh,
 -    Saying his designs for stego might as well be made of lego
 -      And that my bikeshed was prettier by half.
 -
 -    But Claude Shannon saw my shame. From his noiseless channel came
 -       A message sent with not a wasted byte
 -    "There are nine and sixty ways to disguise communiques
 -       And RATHER MORE THAN ONE OF THEM IS RIGHT"
 -
 -\t\t    (apologies to Rudyard Kipling.)
 -
 obfsproxy server stderr:
 | 2012-04-13 14:41:02 [notice] Starting (git-8cf684e052cf290e).
 | 2012-04-13 14:41:02 [debug] Configuration 1: dummy server 127.0.0.1:5000
 127.0.0.1:5001
 | 2012-04-13 14:41:02 [debug] Now listening on 127.0.0.1:5000 for protocol
 dummy.
 | 2012-04-13 14:41:02 [debug] [scrubbed]: new connection from [scrubbed]
 (1 total)
 | 2012-04-13 14:41:02 [debug] [scrubbed]: server connection
 | 2012-04-13 14:41:02 [info] [scrubbed] (dummy): Successful outbound
 connection to '[scrubbed]'.
 | 2012-04-13 14:41:02 [debug] [scrubbed]: setup complete
 | 2012-04-13 14:41:02 [debug] [scrubbed]: pending_conn_cb
 | 2012-04-13 14:41:02 [debug] [scrubbed]: Successful connection
 | 2012-04-13 14:41:02 [debug] [scrubbed]: downstream_read_cb, 1666 bytes
 available
 | 2012-04-13 14:41:02 [debug] [scrubbed]: forwarded 1666 bytes
 | 2012-04-13 14:41:03 [debug] error_cb for [scrubbed]: what=0x0011
 | 2012-04-13 14:41:03 [info] EOF from [scrubbed]
 | 2012-04-13 14:41:03 [debug] error_or_eof for [scrubbed]
 | 2012-04-13 14:41:03 [debug] Closing connection with [scrubbed]; 1
 remaining
 | 2012-04-13 14:41:03 [debug] Closing connection with [scrubbed]; 0
 remaining
 | 2012-04-13 14:41:03 [info] Closing all listeners.
 | 2012-04-13 14:41:03 [notice] Got SIGINT. Preparing shutdown.
 | 2012-04-13 14:41:03 [debug] Beginning normal shutdown.
 | 2012-04-13 14:41:03 [debug] Finishing shutdown.
 | 2012-04-13 14:41:03 [notice] Exiting.
 obfsproxy client stderr:
 | 2012-04-13 14:41:02 [notice] Starting (git-8cf684e052cf290e).
 | 2012-04-13 14:41:02 [debug] Configuration 1: dummy socks 127.0.0.1:4999
 | 2012-04-13 14:41:02 [debug] Now listening on 127.0.0.1:4999 for protocol
 dummy.
 | 2012-04-13 14:41:02 [debug] [scrubbed]: new connection from [scrubbed]
 (1 total)
 | 2012-04-13 14:41:02 [debug] [scrubbed]: socks client connection
 | 2012-04-13 14:41:02 [debug] [scrubbed]: setup complete
 | 2012-04-13 14:41:02 [debug] [scrubbed]: socks_read_cb
 | 2012-04-13 14:41:02 [debug] Got version 5
 | 2012-04-13 14:41:02 [debug] socks: request packet is too small (1).
 | 2012-04-13 14:41:02 [debug] [scrubbed]: socks_read_cb
 | 2012-04-13 14:41:02 [info] [scrubbed]: socks: trying to connect to
 [scrubbed]:5000
 | 2012-04-13 14:41:02 [debug] [scrubbed]: pending_socks_cb
 | 2012-04-13 14:41:02 [debug] We connected to our SOCKS destination!
 Replacing peername '[scrubbed]' with '[scrubbed]'
 | 2012-04-13 14:41:02 [debug] [scrubbed]: Successful outbound connection
 to [scrubbed]
 | 2012-04-13 14:41:02 [debug] [scrubbed]: upstream_read_cb, 1666 bytes
 available
 | 2012-04-13 14:41:02 [debug] [scrubbed]: transmitted 1666 bytes
 | 2012-04-13 14:41:03 [debug] error_cb for [scrubbed]: what=0x0011
 | 2012-04-13 14:41:03 [info] EOF from [scrubbed]
 | 2012-04-13 14:41:03 [debug] error_or_eof for [scrubbed]
 | 2012-04-13 14:41:03 [debug] Closing connection with [scrubbed]; 1
 remaining
 | 2012-04-13 14:41:03 [debug] Closing connection with [scrubbed]; 0
 remaining
 | 2012-04-13 14:41:03 [info] Closing all listeners.
 | 2012-04-13 14:41:03 [notice] Got SIGINT. Preparing shutdown.
 | 2012-04-13 14:41:03 [debug] Beginning normal shutdown.
 | 2012-04-13 14:41:03 [debug] Finishing shutdown.
 | 2012-04-13 14:41:03 [notice] Exiting.
 }}}

 This might be related to #5617.

-- 
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/5619>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online


More information about the tor-bugs mailing list