Make prefixes in verbose output more consistent.

Use 'c' prefix for client, 's' prefix for server, and 'fw' prefix for
firewall messages. The 'c' and 's' prefixes were used sometimes but
not consistently. The firewall printed messages prefixed with
"firewall manager:" or "firewall:" or ">>" previously.

This patch also fixes a couple of print() calls that should have been
debug1()---a bug introduced in a recent commit.

sshuttle/assembler.py

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

sshuttle/client.py

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

sshuttle/firewall.py

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

sshuttle/linux.py

@@ -8,7 +8,7 @@ def nonfatal(func, *args):
     try:
         func(*args)
     except Fatal as e:
-        log('error: %s\n' % e)
+        log('fw: error: %s\n' % e)
 
 
 def ipt_chain_exists(family, table, name):
@@ -29,7 +29,7 @@ def ipt_chain_exists(family, table, name):
             if line.startswith('Chain %s ' % name):
                 return True
     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):
@@ -39,14 +39,14 @@ def ipt(family, table, *args):
         argv = ['iptables', '-t', table] + list(args)
     else:
         raise Exception('Unsupported family "%s"' % family_to_string(family))
-    debug1('>> %s\n' % ' '.join(argv))
+    debug1('%s\n' % ' '.join(argv))
     env = {
         'PATH': os.environ['PATH'],
         'LC_ALL': "C",
     }
     rv = ssubprocess.call(argv, env=env)
     if rv:
-        raise Fatal('%r returned %d' % (argv, rv))
+        raise Fatal('fw: %r returned %d' % (argv, rv))
 
 
 def nft(family, table, action, *args):
@@ -54,14 +54,14 @@ def nft(family, table, action, *args):
         argv = ['nft', action, 'inet', table] + list(args)
     else:
         raise Exception('Unsupported family "%s"' % family_to_string(family))
-    debug1('>> %s\n' % ' '.join(argv))
+    debug1('%s\n' % ' '.join(argv))
     env = {
         'PATH': os.environ['PATH'],
         'LC_ALL': "C",
     }
     rv = ssubprocess.call(argv, env=env)
     if rv:
-        raise Fatal('%r returned %d' % (argv, rv))
+        raise Fatal('fw: %r returned %d' % (argv, rv))
 
 
 _no_ttl_module = False
@@ -79,7 +79,7 @@ def ipt_ttl(family, *args):
         except Fatal:
             ipt(family, *args)
             # 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')
             _no_ttl_module = True
     else:

sshuttle/server.py

@@ -273,12 +273,12 @@ class UdpProxy(Handler):
             self.sock.setsockopt(socket.SOL_IP, socket.IP_TTL, 63)
 
     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:
             self.sock.sendto(data, dstip)
         except socket.error:
             _, 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
 
     def callback(self, sock):
@@ -286,21 +286,18 @@ class UdpProxy(Handler):
             data, peer = sock.recvfrom(4096)
         except socket.error:
             _, 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
-        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]))
         self.mux.send(self.chan, ssnet.CMD_UDP_DATA, hdr + data)
 
 
 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())
 
-    if helpers.verbose >= 1:
-        helpers.logprefix = ' s: '
-    else:
-        helpers.logprefix = 'server: '
+    helpers.logprefix = ' s: '
     debug1('latency control setting = %r\n' % latency_control)
 
     # synchronization header
@@ -341,7 +338,7 @@ def main(latency_control, auto_hosts, to_nameserver, auto_nets):
                 hw.leftover = b('')
             mux.send(0, ssnet.CMD_HOST_LIST, b('\n').join(lines))
         else:
-            raise Fatal('hostwatch process died')
+            raise Fatal(' s: hostwatch process died')
 
     def got_host_req(data):
         if not hw.pid:
@@ -395,7 +392,7 @@ def main(latency_control, auto_hosts, to_nameserver, auto_nets):
         family = int(data)
         mux.channels[channel] = lambda cmd, data: udp_req(channel, cmd, data)
         if channel in udphandlers:
-            raise Fatal('UDP connection channel %d already open' % channel)
+            raise Fatal(' s: UDP connection channel %d already open' % channel)
         else:
             h = UdpProxy(mux, channel, family)
             handlers.append(h)