Merge pull request #548 from skuhl/stdout-cleanup

Make prefixes in verbose output more consistent.
This commit is contained in:
Brian May 2020-10-21 07:53:14 +11:00 committed by GitHub
commit 1f3c74a1af
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 67 additions and 76 deletions

View File

@ -14,7 +14,7 @@ while 1:
name = name.decode("ASCII") name = name.decode("ASCII")
nbytes = int(sys.stdin.readline()) nbytes = int(sys.stdin.readline())
if verbosity >= 2: if verbosity >= 2:
sys.stderr.write('server: assembling %r (%d bytes)\n' sys.stderr.write(' s: assembling %r (%d bytes)\n'
% (name, nbytes)) % (name, nbytes))
content = z.decompress(sys.stdin.read(nbytes)) content = z.decompress(sys.stdin.read(nbytes))

View File

@ -57,7 +57,7 @@ def check_daemon(pidfile):
if e.errno == errno.ENOENT: if e.errno == errno.ENOENT:
return # no pidfile, ok return # no pidfile, ok
else: else:
raise Fatal("can't read %s: %s" % (_pidname, e)) raise Fatal("c : can't read %s: %s" % (_pidname, e))
if not oldpid: if not oldpid:
os.unlink(_pidname) os.unlink(_pidname)
return # invalid pidfile, ok return # invalid pidfile, ok
@ -433,17 +433,14 @@ def _main(tcp_listener, udp_listener, fw, ssh_cmd, remotename,
dns_listener, seed_hosts, auto_hosts, auto_nets, daemon, dns_listener, seed_hosts, auto_hosts, auto_nets, daemon,
to_nameserver): to_nameserver):
helpers.logprefix = 'c : '
debug1('Starting client with Python version %s\n' debug1('Starting client with Python version %s\n'
% platform.python_version()) % platform.python_version())
method = fw.method method = fw.method
handlers = [] handlers = []
if helpers.verbose >= 1: debug1('Connecting to server...\n')
helpers.logprefix = 'c : '
else:
helpers.logprefix = 'client: '
debug1('connecting to server...\n')
try: try:
(serverproc, serversock) = ssh.connect( (serverproc, serversock) = ssh.connect(
@ -455,7 +452,7 @@ def _main(tcp_listener, udp_listener, fw, ssh_cmd, remotename,
auto_nets=auto_nets)) auto_nets=auto_nets))
except socket.error as e: except socket.error as e:
if e.args[0] == errno.EPIPE: if e.args[0] == errno.EPIPE:
raise Fatal("failed to establish ssh session (1)") raise Fatal("c : failed to establish ssh session (1)")
else: else:
raise raise
mux = Mux(serversock.makefile("rb"), serversock.makefile("wb")) mux = Mux(serversock.makefile("rb"), serversock.makefile("wb"))
@ -473,18 +470,18 @@ def _main(tcp_listener, udp_listener, fw, ssh_cmd, remotename,
initstring = serversock.recv(len(expected)) initstring = serversock.recv(len(expected))
except socket.error as e: except socket.error as e:
if e.args[0] == errno.ECONNRESET: if e.args[0] == errno.ECONNRESET:
raise Fatal("failed to establish ssh session (2)") raise Fatal("c : failed to establish ssh session (2)")
else: else:
raise raise
rv = serverproc.poll() rv = serverproc.poll()
if rv: if rv:
raise Fatal('server died with error code %d' % rv) raise Fatal('c : server died with error code %d' % rv)
if initstring != expected: if initstring != expected:
raise Fatal('expected server init string %r; got %r' raise Fatal('c : expected server init string %r; got %r'
% (expected, initstring)) % (expected, initstring))
log('Connected.\n') log('Connected to server.\n')
sys.stdout.flush() sys.stdout.flush()
if daemon: if daemon:
daemonize() daemonize()
@ -583,6 +580,7 @@ def main(listenip_v6, listenip_v4,
log("%s\n" % e) log("%s\n" % e)
return 5 return 5
debug1('Starting sshuttle proxy (version %s).\n' % __version__) debug1('Starting sshuttle proxy (version %s).\n' % __version__)
helpers.logprefix = 'c : '
fw = FirewallClient(method_name, sudo_pythonpath) fw = FirewallClient(method_name, sudo_pythonpath)
@ -737,18 +735,18 @@ def main(listenip_v6, listenip_v4,
debug1("Subnets to forward through remote host (type, IP, cidr mask " debug1("Subnets to forward through remote host (type, IP, cidr mask "
"width, startPort, endPort):\n") "width, startPort, endPort):\n")
for i in subnets_include: for i in subnets_include:
print(" "+str(i)) debug1(" "+str(i)+"\n")
if auto_nets: if auto_nets:
debug1("NOTE: Additional subnets to forward may be added below by " debug1("NOTE: Additional subnets to forward may be added below by "
"--auto-nets.\n") "--auto-nets.\n")
debug1("Subnets to exclude from forwarding:\n") debug1("Subnets to exclude from forwarding:\n")
for i in subnets_exclude: for i in subnets_exclude:
print(" "+str(i)) debug1(" "+str(i)+"\n")
if required.dns: if required.dns:
debug1("DNS requests normally directed at these servers will be " debug1("DNS requests normally directed at these servers will be "
"redirected to remote:\n") "redirected to remote:\n")
for i in nslist: for i in nslist:
print(" "+str(i)) debug1(" "+str(i)+"\n")
if listenip_v6 and listenip_v6[1] and listenip_v4 and listenip_v4[1]: if listenip_v6 and listenip_v6[1] and listenip_v4 and listenip_v4[1]:
# if both ports given, no need to search for a spare port # if both ports given, no need to search for a spare port
@ -765,9 +763,8 @@ def main(listenip_v6, listenip_v4,
redirectport_v6 = 0 redirectport_v6 = 0
redirectport_v4 = 0 redirectport_v4 = 0
bound = False bound = False
debug2('Binding redirector:')
for port in ports: for port in ports:
debug2(' %d' % port) debug2('Trying to bind redirector on port %d\n' % port)
tcp_listener = MultiListener() tcp_listener = MultiListener()
if required.udp: if required.udp:
@ -809,7 +806,6 @@ def main(listenip_v6, listenip_v4,
else: else:
raise e raise e
debug2('\n')
if not bound: if not bound:
assert(last_e) assert(last_e)
raise last_e raise last_e
@ -821,10 +817,9 @@ def main(listenip_v6, listenip_v4,
bound = False bound = False
if required.dns: if required.dns:
# search for spare port for DNS # search for spare port for DNS
debug2('Binding DNS:')
ports = range(12300, 9000, -1) ports = range(12300, 9000, -1)
for port in ports: for port in ports:
debug2(' %d' % port) debug2('Trying to bind DNS redirector on port %d\n' % port)
if port in used_ports: if port in used_ports:
continue continue
@ -855,7 +850,7 @@ def main(listenip_v6, listenip_v4,
used_ports.append(port) used_ports.append(port)
else: else:
raise e raise e
debug2('\n')
dns_listener.print_listening("DNS") dns_listener.print_listening("DNS")
if not bound: if not bound:
assert(last_e) assert(last_e)

View File

@ -7,6 +7,7 @@ import platform
import traceback import traceback
import sshuttle.ssyslog as ssyslog import sshuttle.ssyslog as ssyslog
import sshuttle.helpers as helpers
from sshuttle.helpers import debug1, debug2, Fatal from sshuttle.helpers import debug1, debug2, Fatal
from sshuttle.methods import get_auto_method, get_method from sshuttle.methods import get_auto_method, get_method
@ -50,14 +51,15 @@ def rewrite_etc_hosts(hostmap, port):
def restore_etc_hosts(hostmap, port): def restore_etc_hosts(hostmap, port):
# Only restore if we added hosts to /etc/hosts previously. # Only restore if we added hosts to /etc/hosts previously.
if len(hostmap) > 0: if len(hostmap) > 0:
debug2('firewall manager: undoing /etc/hosts changes.\n') debug2('undoing /etc/hosts changes.\n')
rewrite_etc_hosts({}, port) rewrite_etc_hosts({}, port)
# Isolate function that needs to be replaced for tests # Isolate function that needs to be replaced for tests
def setup_daemon(): def setup_daemon():
if os.getuid() != 0: if os.getuid() != 0:
raise Fatal('you must be root (or enable su/sudo) to set the firewall') raise Fatal('fw: '
'You must be root (or enable su/sudo) to set the firewall')
# don't disappear if our controlling terminal or stdout/stderr # don't disappear if our controlling terminal or stdout/stderr
# disappears; we still have to clean up. # disappears; we still have to clean up.
@ -99,8 +101,8 @@ def subnet_weight(s):
def main(method_name, syslog): def main(method_name, syslog):
stdin, stdout = setup_daemon() stdin, stdout = setup_daemon()
hostmap = {} hostmap = {}
helpers.logprefix = 'fw: '
debug1('firewall manager: Starting firewall with Python version %s\n' debug1('Starting firewall with Python version %s\n'
% platform.python_version()) % platform.python_version())
if method_name == "auto": if method_name == "auto":
@ -112,7 +114,7 @@ def main(method_name, syslog):
ssyslog.start_syslog() ssyslog.start_syslog()
ssyslog.stderr_to_syslog() ssyslog.stderr_to_syslog()
debug1('firewall manager: ready method name %s.\n' % method.name) debug1('ready method name %s.\n' % method.name)
stdout.write('READY %s\n' % method.name) stdout.write('READY %s\n' % method.name)
stdout.flush() stdout.flush()
@ -125,18 +127,18 @@ def main(method_name, syslog):
subnets = [] subnets = []
if line != 'ROUTES\n': if line != 'ROUTES\n':
raise Fatal('firewall: expected ROUTES but got %r' % line) raise Fatal('expected ROUTES but got %r' % line)
while 1: while 1:
line = stdin.readline(128) line = stdin.readline(128)
if not line: if not line:
raise Fatal('firewall: expected route but got %r' % line) raise Fatal('fw: expected route but got %r' % line)
elif line.startswith("NSLIST\n"): elif line.startswith("NSLIST\n"):
break break
try: try:
(family, width, exclude, ip, fport, lport) = \ (family, width, exclude, ip, fport, lport) = \
line.strip().split(',', 5) line.strip().split(',', 5)
except BaseException: except BaseException:
raise Fatal('firewall: expected route or NSLIST but got %r' % line) raise Fatal('fw: expected route or NSLIST but got %r' % line)
subnets.append(( subnets.append((
int(family), int(family),
int(width), int(width),
@ -144,31 +146,31 @@ def main(method_name, syslog):
ip, ip,
int(fport), int(fport),
int(lport))) int(lport)))
debug2('firewall manager: Got subnets: %r\n' % subnets) debug2('Got subnets: %r\n' % subnets)
nslist = [] nslist = []
if line != 'NSLIST\n': if line != 'NSLIST\n':
raise Fatal('firewall: expected NSLIST but got %r' % line) raise Fatal('fw: expected NSLIST but got %r' % line)
while 1: while 1:
line = stdin.readline(128) line = stdin.readline(128)
if not line: if not line:
raise Fatal('firewall: expected nslist but got %r' % line) raise Fatal('fw: expected nslist but got %r' % line)
elif line.startswith("PORTS "): elif line.startswith("PORTS "):
break break
try: try:
(family, ip) = line.strip().split(',', 1) (family, ip) = line.strip().split(',', 1)
except BaseException: except BaseException:
raise Fatal('firewall: expected nslist or PORTS but got %r' % line) raise Fatal('fw: expected nslist or PORTS but got %r' % line)
nslist.append((int(family), ip)) nslist.append((int(family), ip))
debug2('firewall manager: Got partial nslist: %r\n' % nslist) debug2('Got partial nslist: %r\n' % nslist)
debug2('firewall manager: Got nslist: %r\n' % nslist) debug2('Got nslist: %r\n' % nslist)
if not line.startswith('PORTS '): if not line.startswith('PORTS '):
raise Fatal('firewall: expected PORTS but got %r' % line) raise Fatal('fw: expected PORTS but got %r' % line)
_, _, ports = line.partition(" ") _, _, ports = line.partition(" ")
ports = ports.split(",") ports = ports.split(",")
if len(ports) != 4: if len(ports) != 4:
raise Fatal('firewall: expected 4 ports but got %d' % len(ports)) raise Fatal('fw: expected 4 ports but got %d' % len(ports))
port_v6 = int(ports[0]) port_v6 = int(ports[0])
port_v4 = int(ports[1]) port_v4 = int(ports[1])
dnsport_v6 = int(ports[2]) dnsport_v6 = int(ports[2])
@ -183,21 +185,21 @@ def main(method_name, syslog):
assert(dnsport_v4 >= 0) assert(dnsport_v4 >= 0)
assert(dnsport_v4 <= 65535) assert(dnsport_v4 <= 65535)
debug2('firewall manager: Got ports: %d,%d,%d,%d\n' debug2('Got ports: %d,%d,%d,%d\n'
% (port_v6, port_v4, dnsport_v6, dnsport_v4)) % (port_v6, port_v4, dnsport_v6, dnsport_v4))
line = stdin.readline(128) line = stdin.readline(128)
if not line: if not line:
raise Fatal('firewall: expected GO but got %r' % line) raise Fatal('fw: expected GO but got %r' % line)
elif not line.startswith("GO "): elif not line.startswith("GO "):
raise Fatal('firewall: expected GO but got %r' % line) raise Fatal('fw: expected GO but got %r' % line)
_, _, args = line.partition(" ") _, _, args = line.partition(" ")
udp, user = args.strip().split(" ", 1) udp, user = args.strip().split(" ", 1)
udp = bool(int(udp)) udp = bool(int(udp))
if user == '-': if user == '-':
user = None user = None
debug2('firewall manager: Got udp: %r, user: %r\n' % (udp, user)) debug2('Got udp: %r, user: %r\n' % (udp, user))
subnets_v6 = [i for i in subnets if i[0] == socket.AF_INET6] subnets_v6 = [i for i in subnets if i[0] == socket.AF_INET6]
nslist_v6 = [i for i in nslist if i[0] == socket.AF_INET6] nslist_v6 = [i for i in nslist if i[0] == socket.AF_INET6]
@ -205,17 +207,17 @@ def main(method_name, syslog):
nslist_v4 = [i for i in nslist if i[0] == socket.AF_INET] nslist_v4 = [i for i in nslist if i[0] == socket.AF_INET]
try: try:
debug1('firewall manager: setting up.\n') debug1('setting up.\n')
if subnets_v6 or nslist_v6: if subnets_v6 or nslist_v6:
debug2('firewall manager: setting up IPv6.\n') debug2('setting up IPv6.\n')
method.setup_firewall( method.setup_firewall(
port_v6, dnsport_v6, nslist_v6, port_v6, dnsport_v6, nslist_v6,
socket.AF_INET6, subnets_v6, udp, socket.AF_INET6, subnets_v6, udp,
user) user)
if subnets_v4 or nslist_v4: if subnets_v4 or nslist_v4:
debug2('firewall manager: setting up IPv4.\n') debug2('setting up IPv4.\n')
method.setup_firewall( method.setup_firewall(
port_v4, dnsport_v4, nslist_v4, port_v4, dnsport_v4, nslist_v4,
socket.AF_INET, subnets_v4, udp, socket.AF_INET, subnets_v4, udp,
@ -238,27 +240,26 @@ def main(method_name, syslog):
if line.startswith('HOST '): if line.startswith('HOST '):
(name, ip) = line[5:].strip().split(',', 1) (name, ip) = line[5:].strip().split(',', 1)
hostmap[name] = ip hostmap[name] = ip
debug2('firewall manager: setting up /etc/hosts.\n') debug2('setting up /etc/hosts.\n')
rewrite_etc_hosts(hostmap, port_v6 or port_v4) rewrite_etc_hosts(hostmap, port_v6 or port_v4)
elif line: elif line:
if not method.firewall_command(line): if not method.firewall_command(line):
raise Fatal('firewall: expected command, got %r' % line) raise Fatal('fw: expected command, got %r' % line)
else: else:
break break
finally: finally:
try: try:
debug1('firewall manager: undoing changes.\n') debug1('undoing changes.\n')
except BaseException: except BaseException:
debug2('An error occurred, ignoring it.') debug2('An error occurred, ignoring it.')
try: try:
if subnets_v6 or nslist_v6: if subnets_v6 or nslist_v6:
debug2('firewall manager: undoing IPv6 changes.\n') debug2('undoing IPv6 changes.\n')
method.restore_firewall(port_v6, socket.AF_INET6, udp, user) method.restore_firewall(port_v6, socket.AF_INET6, udp, user)
except BaseException: except BaseException:
try: try:
debug1("firewall manager: " debug1("Error trying to undo IPv6 firewall.\n")
"Error trying to undo IPv6 firewall.\n")
for line in traceback.format_exc().splitlines(): for line in traceback.format_exc().splitlines():
debug1("---> %s\n" % line) debug1("---> %s\n" % line)
except BaseException: except BaseException:
@ -266,14 +267,13 @@ def main(method_name, syslog):
try: try:
if subnets_v4 or nslist_v4: if subnets_v4 or nslist_v4:
debug2('firewall manager: undoing IPv4 changes.\n') debug2('undoing IPv4 changes.\n')
method.restore_firewall(port_v4, socket.AF_INET, udp, user) method.restore_firewall(port_v4, socket.AF_INET, udp, user)
except BaseException: except BaseException:
try: try:
debug1("firewall manager: " debug1("Error trying to undo IPv4 firewall.\n")
"Error trying to undo IPv4 firewall.\n")
for line in traceback.format_exc().splitlines(): for line in traceback.format_exc().splitlines():
debug1("firewall manager: ---> %s\n" % line) debug1("---> %s\n" % line)
except BaseException: except BaseException:
debug2('An error occurred, ignoring it.') debug2('An error occurred, ignoring it.')
@ -282,9 +282,8 @@ def main(method_name, syslog):
restore_etc_hosts(hostmap, port_v6 or port_v4) restore_etc_hosts(hostmap, port_v6 or port_v4)
except BaseException: except BaseException:
try: try:
debug1("firewall manager: " debug1("Error trying to undo /etc/hosts changes.\n")
"Error trying to undo /etc/hosts changes.\n")
for line in traceback.format_exc().splitlines(): for line in traceback.format_exc().splitlines():
debug1("firewall manager: ---> %s\n" % line) debug1("---> %s\n" % line)
except BaseException: except BaseException:
debug2('An error occurred, ignoring it.') debug2('An error occurred, ignoring it.')

View File

@ -8,7 +8,7 @@ def nonfatal(func, *args):
try: try:
func(*args) func(*args)
except Fatal as e: except Fatal as e:
log('error: %s\n' % e) log('fw: error: %s\n' % e)
def ipt_chain_exists(family, table, name): def ipt_chain_exists(family, table, name):
@ -29,7 +29,7 @@ def ipt_chain_exists(family, table, name):
if line.startswith('Chain %s ' % name): if line.startswith('Chain %s ' % name):
return True return True
except ssubprocess.CalledProcessError as e: except ssubprocess.CalledProcessError as e:
raise Fatal('%r returned %d' % (argv, e.returncode)) raise Fatal('fw: %r returned %d' % (argv, e.returncode))
def ipt(family, table, *args): def ipt(family, table, *args):
@ -39,14 +39,14 @@ def ipt(family, table, *args):
argv = ['iptables', '-t', table] + list(args) argv = ['iptables', '-t', table] + list(args)
else: else:
raise Exception('Unsupported family "%s"' % family_to_string(family)) raise Exception('Unsupported family "%s"' % family_to_string(family))
debug1('>> %s\n' % ' '.join(argv)) debug1('%s\n' % ' '.join(argv))
env = { env = {
'PATH': os.environ['PATH'], 'PATH': os.environ['PATH'],
'LC_ALL': "C", 'LC_ALL': "C",
} }
rv = ssubprocess.call(argv, env=env) rv = ssubprocess.call(argv, env=env)
if rv: if rv:
raise Fatal('%r returned %d' % (argv, rv)) raise Fatal('fw: %r returned %d' % (argv, rv))
def nft(family, table, action, *args): def nft(family, table, action, *args):
@ -54,14 +54,14 @@ def nft(family, table, action, *args):
argv = ['nft', action, 'inet', table] + list(args) argv = ['nft', action, 'inet', table] + list(args)
else: else:
raise Exception('Unsupported family "%s"' % family_to_string(family)) raise Exception('Unsupported family "%s"' % family_to_string(family))
debug1('>> %s\n' % ' '.join(argv)) debug1('%s\n' % ' '.join(argv))
env = { env = {
'PATH': os.environ['PATH'], 'PATH': os.environ['PATH'],
'LC_ALL': "C", 'LC_ALL': "C",
} }
rv = ssubprocess.call(argv, env=env) rv = ssubprocess.call(argv, env=env)
if rv: if rv:
raise Fatal('%r returned %d' % (argv, rv)) raise Fatal('fw: %r returned %d' % (argv, rv))
_no_ttl_module = False _no_ttl_module = False
@ -79,7 +79,7 @@ def ipt_ttl(family, *args):
except Fatal: except Fatal:
ipt(family, *args) ipt(family, *args)
# we only get here if the non-ttl attempt succeeds # we only get here if the non-ttl attempt succeeds
log('sshuttle: warning: your iptables is missing ' log('fw: WARNING: your iptables is missing '
'the ttl module.\n') 'the ttl module.\n')
_no_ttl_module = True _no_ttl_module = True
else: else:

View File

@ -273,12 +273,12 @@ class UdpProxy(Handler):
self.sock.setsockopt(socket.SOL_IP, socket.IP_TTL, 63) self.sock.setsockopt(socket.SOL_IP, socket.IP_TTL, 63)
def send(self, dstip, data): def send(self, dstip, data):
debug2('UDP: sending to %r port %d\n' % dstip) debug2(' s: UDP: sending to %r port %d\n' % dstip)
try: try:
self.sock.sendto(data, dstip) self.sock.sendto(data, dstip)
except socket.error: except socket.error:
_, e = sys.exc_info()[:2] _, e = sys.exc_info()[:2]
log('UDP send to %r port %d: %s\n' % (dstip[0], dstip[1], e)) log(' s: UDP send to %r port %d: %s\n' % (dstip[0], dstip[1], e))
return return
def callback(self, sock): def callback(self, sock):
@ -286,21 +286,18 @@ class UdpProxy(Handler):
data, peer = sock.recvfrom(4096) data, peer = sock.recvfrom(4096)
except socket.error: except socket.error:
_, e = sys.exc_info()[:2] _, e = sys.exc_info()[:2]
log('UDP recv from %r port %d: %s\n' % (peer[0], peer[1], e)) log(' s: UDP recv from %r port %d: %s\n' % (peer[0], peer[1], e))
return return
debug2('UDP response: %d bytes\n' % len(data)) debug2(' s: UDP response: %d bytes\n' % len(data))
hdr = b("%s,%r," % (peer[0], peer[1])) hdr = b("%s,%r," % (peer[0], peer[1]))
self.mux.send(self.chan, ssnet.CMD_UDP_DATA, hdr + data) self.mux.send(self.chan, ssnet.CMD_UDP_DATA, hdr + data)
def main(latency_control, auto_hosts, to_nameserver, auto_nets): def main(latency_control, auto_hosts, to_nameserver, auto_nets):
debug1('Starting server with Python version %s\n' debug1(' s: Starting server with Python version %s\n'
% platform.python_version()) % platform.python_version())
if helpers.verbose >= 1:
helpers.logprefix = ' s: ' helpers.logprefix = ' s: '
else:
helpers.logprefix = 'server: '
debug1('latency control setting = %r\n' % latency_control) debug1('latency control setting = %r\n' % latency_control)
# synchronization header # synchronization header
@ -341,7 +338,7 @@ def main(latency_control, auto_hosts, to_nameserver, auto_nets):
hw.leftover = b('') hw.leftover = b('')
mux.send(0, ssnet.CMD_HOST_LIST, b('\n').join(lines)) mux.send(0, ssnet.CMD_HOST_LIST, b('\n').join(lines))
else: else:
raise Fatal('hostwatch process died') raise Fatal(' s: hostwatch process died')
def got_host_req(data): def got_host_req(data):
if not hw.pid: if not hw.pid:
@ -395,7 +392,7 @@ def main(latency_control, auto_hosts, to_nameserver, auto_nets):
family = int(data) family = int(data)
mux.channels[channel] = lambda cmd, data: udp_req(channel, cmd, data) mux.channels[channel] = lambda cmd, data: udp_req(channel, cmd, data)
if channel in udphandlers: if channel in udphandlers:
raise Fatal('UDP connection channel %d already open' % channel) raise Fatal(' s: UDP connection channel %d already open' % channel)
else: else:
h = UdpProxy(mux, channel, family) h = UdpProxy(mux, channel, family)
handlers.append(h) handlers.append(h)