open.source/magic-wormhole
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

transit.py: add debug prints, disabled

Browse Source
This commit is contained in:
Brian Warner 2015-03-12 16:03:00 -07:00
parent 35630661a5
commit cedd04a2fb
1 changed files with 21 additions and 7 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

28
src/wormhole/blocking/transit.py
View File

@ -1,5 +1,5 @@
from __future__ import print_function from __future__ import print_function
import re, threading, socket, SocketServer import re, time, threading, socket, SocketServer
from binascii import hexlify from binascii import hexlify
from ..util import ipaddrs from ..util import ipaddrs
from ..util.hkdf import HKDF from ..util.hkdf import HKDF
@ -109,26 +109,36 @@ def parse_hint_tcp(hint):
return None return None
return hint_host, hint_port return hint_host, hint_port
def debug(msg):
if False:
print(msg)
def since(start):
return time.time() - start
def connector(owner, hint, description, def connector(owner, hint, description,
send_handshake, expected_handshake, relay_handshake=None): send_handshake, expected_handshake, relay_handshake=None):
start = time.time()
parsed_hint = parse_hint_tcp(hint) parsed_hint = parse_hint_tcp(hint)
if not parsed_hint: if not parsed_hint:
return # unparseable return # unparseable
addr,port = parsed_hint addr,port = parsed_hint
skt = None skt = None
debug("+ connector(%s)" % hint)
try: try:
skt = socket.create_connection((addr,port), skt = socket.create_connection((addr,port),
TIMEOUT) # timeout or ECONNREFUSED TIMEOUT) # timeout or ECONNREFUSED
skt.settimeout(TIMEOUT) skt.settimeout(TIMEOUT)
#print("socket(%s) connected" % (description,)) debug(" - socket(%s) connected CT+%.1f" % (description, since(start)))
if relay_handshake: if relay_handshake:
debug(" - sending relay_handshake")
send_to(skt, relay_handshake) send_to(skt, relay_handshake)
wait_for(skt, "ok\n", description) wait_for(skt, "ok\n", description)
#print("relay ready %r" % (description,)) debug(" - relay ready CT+%.1f" % (since(start),))
send_to(skt, send_handshake) send_to(skt, send_handshake)
wait_for(skt, expected_handshake, description) wait_for(skt, expected_handshake, description)
#print("connector ready %r" % (description,)) debug(" + connector(%s) ready CT+%.1f" % (hint, since(start)))
except Exception as e: except Exception as e:
debug(" - timeout(%s) CT+%.1f" % (hint, since(start)))
try: try:
if skt: if skt:
skt.shutdown(socket.SHUT_WR) skt.shutdown(socket.SHUT_WR)
@ -139,6 +149,7 @@ def connector(owner, hint, description,
# ignore socket errors, warn about coding errors # ignore socket errors, warn about coding errors
if not isinstance(e, (socket.error, socket.timeout, BadHandshake)): if not isinstance(e, (socket.error, socket.timeout, BadHandshake)):
raise raise
debug(" - notifying owner._connector_failed(%s) CT+%.1f" % (hint, since(start)))
owner._connector_failed(hint) owner._connector_failed(hint)
return return
# owner is now responsible for the socket # owner is now responsible for the socket
@ -147,7 +158,7 @@ def connector(owner, hint, description,
def handle(skt, client_address, owner, description, def handle(skt, client_address, owner, description,
send_handshake, expected_handshake): send_handshake, expected_handshake):
try: try:
#print("handle %r" % (skt,)) debug("handle %r" % (skt,))
skt.settimeout(TIMEOUT) skt.settimeout(TIMEOUT)
send_to(skt, send_handshake) send_to(skt, send_handshake)
got = b"" got = b""
@ -160,9 +171,9 @@ def handle(skt, client_address, owner, description,
if expected_handshake[:len(got)] != got: if expected_handshake[:len(got)] != got:
raise BadHandshake("got '%r' want '%r'" % raise BadHandshake("got '%r' want '%r'" %
(got, expected_handshake)) (got, expected_handshake))
#print("handler negotiation finished %r" % (client_address,)) debug("handler negotiation finished %r" % (client_address,))
except Exception as e: except Exception as e:
#print("handler failed %r" % (client_address,)) debug("handler failed %r" % (client_address,))
try: try:
# this raises socket.err(EBADF) if the socket was already closed # this raises socket.err(EBADF) if the socket was already closed
skt.shutdown(socket.SHUT_WR) skt.shutdown(socket.SHUT_WR)
@ -278,12 +289,14 @@ class Common:
self._start_connector(hint, is_relay=True) self._start_connector(hint, is_relay=True)
def establish_connection(self): def establish_connection(self):
start = time.time()
self.winning_skt = None self.winning_skt = None
self.winning_skt_description = None self.winning_skt_description = None
self._start_outbound() self._start_outbound()
# we sit here until one of our inbound or outbound sockets succeeds # we sit here until one of our inbound or outbound sockets succeeds
flag = self.winning.wait(2*TIMEOUT) flag = self.winning.wait(2*TIMEOUT)
debug("wait returned at %.1f" % (since(start),))
if not flag: if not flag:
# timeout: self.winning_skt will not be set. ish. race. # timeout: self.winning_skt will not be set. ish. race.
@ -300,6 +313,7 @@ class Common:
return self.winning_skt_description return self.winning_skt_description
def _connector_failed(self, hint): def _connector_failed(self, hint):
debug("- failed connector %s" % hint)
self._active_connectors.remove(hint) self._active_connectors.remove(hint)
if not self._active_connectors: if not self._active_connectors:
self._start_relay_connectors() self._start_relay_connectors()