From b68c0739e0dbabf20117e637b10ac3cf61ebb783 Mon Sep 17 00:00:00 2001
From: Ian Jackson <ijackson@chiark.greenend.org.uk>
Date: Thu, 30 Mar 2017 00:27:11 +0100
Subject: [PATCH] wip, new logging in server

---
 hippotat/__init__.py | 26 +++++++++++++++-----------
 hippotat/slip.py     |  4 ++--
 server               |  6 +++---
 3 files changed, 20 insertions(+), 16 deletions(-)

diff --git a/hippotat/__init__.py b/hippotat/__init__.py
index 32e6854..35c87f2 100644
--- a/hippotat/__init__.py
+++ b/hippotat/__init__.py
@@ -30,6 +30,7 @@ import hippotat.slip as slip
 
 class DBG(twisted.python.constants.Names):
   ROUTE = NamedConstant()
+  DROP = NamedConstant()
   FLOW = NamedConstant()
   HTTP = NamedConstant()
   HTTP_CTRL = NamedConstant()
@@ -37,7 +38,7 @@ class DBG(twisted.python.constants.Names):
   QUEUE = NamedConstant()
   QUEUE_CTRL = NamedConstant()
 
-_hexcodec = codecs.getencoder('hex_codec')
+_hex_codec = codecs.getencoder('hex_codec')
 
 log = twisted.logger.Logger()
 
@@ -46,7 +47,7 @@ def log_debug(dflag, msg, idof=None, d=None):
     msg = '[%d] %s' % (id(idof), msg)
   if d is not None:
     d = d[0:64]
-    d = _hex_codec(d)[0]
+    d = _hex_codec(d)[0].decode('ascii')
     msg += ' ' + d
   log.info('{dflag} {msgcore}', dflag=dflag, msgcore=msg)
 
@@ -111,10 +112,9 @@ class ConfigResults:
 c = ConfigResults()
 
 def log_discard(packet, saddr, daddr, why):
-  
-  Print('Drop ', Saddr, Daddr, why)
-#  syslog.syslog(syslog.LOG_DEBUG,
-#                'discarded packet %s -> %s (%s)' % (saddr, daddr, why))
+  log_debug(DBG.DROP,
+            'discarded packet %s -> %s (%s)' % (saddr, daddr, why),
+            d=packet)
 
 #---------- packet parsing ----------
 
@@ -211,7 +211,7 @@ class PacketQueue():
     self._max_queue_time = max_queue_time
     self._pq = collections.deque() # packets
 
-  def _log(self, dflag, msg, **kwargs)
+  def _log(self, dflag, msg, **kwargs):
     log_debug(dflag, self._desc+' pq: '+msg, **kwargs)
 
   def append(self, packet):
@@ -253,7 +253,7 @@ class PacketQueue():
 
       self._log(DBG.QUEUE_CTRL,
                 'process... (sofar=%d, max=%d) encoded' % (sofar, max_batch),
-                d=encoded
+                d=encoded)
 
       if sofar > 0:
         if sofar + len(slip.delimiter) + len(encoded) > max_batch:
@@ -266,7 +266,11 @@ class PacketQueue():
 
 #---------- error handling ----------
 
+_crashing = False
+
 def crash(err):
+  global _crashing
+  _crashing = True
   print('CRASH ', err, file=sys.stderr)
   try: reactor.stop()
   except twisted.internet.error.ReactorNotRunning: pass
@@ -290,7 +294,7 @@ def process_cfg_ipif(section, varmap):
     except AttributeError: continue
     setattr(c, d, v)
 
-  print(repr(c))
+  #print(repr(c))
 
   c.ipif_command = cfg.get(section,'ipif', vars=c.__dict__)
 
@@ -363,6 +367,6 @@ def common_startup():
   cfg.read(opts.configfile)
 
 def common_run():
-  log_debug(DBG.INIT, 'ready')
-  reactor.run()
+  log_debug(DBG.INIT, 'entering reactor')
+  if not _crashing: reactor.run()
   print('CRASHED (end)', file=sys.stderr)
diff --git a/hippotat/slip.py b/hippotat/slip.py
index 4e84194..7dbe316 100644
--- a/hippotat/slip.py
+++ b/hippotat/slip.py
@@ -12,7 +12,7 @@ def encode(packet):
           .replace(end, esc + esc_end))
 
 def decode(data):
-  print('DECODE ', repr(data))
+  #print('DECODE ', repr(data))
   out = []
   for packet in data.split(end):
     pdata = b''
@@ -30,7 +30,7 @@ def decode(data):
       else: raise ValueError('invalid SLIP escape')
       packet = packet[eix+2 : ]
     out.append(pdata)
-  print('DECODED ', repr(out))
+  #print('DECODED ', repr(out))
   return out
 # -*- python -*-
 
diff --git a/server b/server
index 6cb8d98..f76f501 100755
--- a/server
+++ b/server
@@ -67,8 +67,8 @@ class Client():
 
     self._log(DBG.INIT, 'new')
 
-  def _log(self, pri, msg, **kwargs):
-    log_debug(pri, 'client '+self._ip+': '+msg, **kwargs)
+  def _log(self, dflag, msg, **kwargs):
+    log_debug(dflag, ('client %s: ' % self._ip)+msg, **kwargs)
 
   def process_arriving_data(self, d):
     self._log(DBG.FLOW, 'req data', d=d)
@@ -144,7 +144,7 @@ def process_request(request, desca):
   desca['ci'] = ci
   cl = clients[ci]
   if pw != cl.pw: raise ValueError('bad password')
-  desca['pwok'=True]
+  desca['pwok']=True
 
   if tro != cl.target_requests_outstanding:
     raise ValueError('tro must be %d' % cl.target_requests_outstanding)
-- 
2.30.2