chiark / gitweb /
crashing and msgs
[hippotat.git] / hippotat / __init__.py
index c57767a..3e8649a 100644 (file)
@@ -7,8 +7,11 @@ import sys
 
 import twisted
 from twisted.internet import reactor
-from twisted.logger import LogLevel
 import twisted.internet.endpoints
+import twisted.logger
+from twisted.logger import LogLevel
+import twisted.python.constants
+from twisted.python.constants import NamedConstant
 
 import ipaddress
 from ipaddress import AddressValueError
@@ -18,11 +21,41 @@ from configparser import ConfigParser
 from configparser import NoOptionError
 
 import collections
+import time
+import codecs
+import traceback
 
 import re as regexp
 
 import hippotat.slip as slip
 
+class DBG(twisted.python.constants.Names):
+  ROUTE = NamedConstant()
+  DROP = NamedConstant()
+  FLOW = NamedConstant()
+  HTTP = NamedConstant()
+  HTTP_CTRL = NamedConstant()
+  INIT = NamedConstant()
+  QUEUE = NamedConstant()
+  QUEUE_CTRL = NamedConstant()
+  HTTP_FULL = NamedConstant()
+  SLIP_FULL = NamedConstant()
+  CTRL_DUMP = NamedConstant()
+
+_hex_codec = codecs.getencoder('hex_codec')
+
+log = twisted.logger.Logger()
+
+def log_debug(dflag, msg, idof=None, d=None):
+  #print('---------------->',repr((dflag, msg, idof, d)), file=sys.stderr)
+  if idof is not None:
+    msg = '[%#x] %s' % (id(idof), msg)
+  if d is not None:
+    d = d[0:64]
+    d = _hex_codec(d)[0].decode('ascii')
+    msg += ' ' + d
+  log.info('{dflag} {msgcore}', dflag=dflag, msgcore=msg)
+
 defcfg = '''
 [DEFAULT]
 #[<client>] overrides
@@ -32,6 +65,8 @@ max_request_time = 54            # used by server, subject to [limits]
 target_requests_outstanding = 3  # must match; subject to [limits] on server
 max_requests_outstanding = 4     # used by client
 max_batch_up = 4000              # used by client
+http_timeout = 30                # used by client
+http_retry = 5                   # used by client
 
 #[server] or [<client>] overrides
 ipif = userv root ipif %(local)s,%(peer)s,%(mtu)s,slip %(rnets)s
@@ -67,6 +102,12 @@ target_requests_outstanding = 10  # used by server
 cfg = ConfigParser()
 optparser = OptionParser()
 
+_mimetrans = bytes.maketrans(b'-'+slip.esc, slip.esc+b'-')
+def mime_translate(s):
+  # SLIP-encoded packets cannot contain ESC ESC.
+  # Swap `-' and ESC.  The result cannot contain `--'
+  return s.translate(_mimetrans)
+
 class ConfigResults:
   def __init__(self, d = { }):
     self.__dict__ = d
@@ -75,10 +116,10 @@ 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))
+def log_discard(packet, iface, saddr, daddr, why):
+  log_debug(DBG.DROP,
+            'discarded packet [%s] %s -> %s: %s' % (iface, saddr, daddr, why),
+            d=packet)
 
 #---------- packet parsing ----------
 
@@ -116,23 +157,49 @@ def ipnetwork(input):
 
 #---------- ipif (SLIP) subprocess ----------
 
+class SlipStreamDecoder():
+  def __init__(self, desc, on_packet):
+    self._buffer = b''
+    self._on_packet = on_packet
+    self._desc = desc
+    self._log('__init__')
+
+  def _log(self, msg, **kwargs):
+    log_debug(DBG.SLIP_FULL, 'slip %s: %s' % (self._desc, msg), **kwargs)
+
+  def inputdata(self, data):
+    self._log('inputdata', d=data)
+    data = self._buffer + data
+    self._buffer = b''
+    packets = slip.decode(data)
+    self._buffer = packets.pop()
+    for packet in packets:
+      self._maybe_packet(packet)
+    self._log('bufremain', d=self._buffer)
+
+  def _maybe_packet(self, packet):
+    self._log('maybepacket', d=packet)
+    if len(packet):
+      self._on_packet(packet)
+
+  def flush(self):
+    self._log('flush')
+    self._maybe_packet(self._buffer)
+    self._buffer = b''
+
 class _IpifProcessProtocol(twisted.internet.protocol.ProcessProtocol):
   def __init__(self, router):
-    self._buffer = b''
     self._router = router
+    self._decoder = SlipStreamDecoder('ipif', self.slip_on_packet)
   def connectionMade(self): pass
   def outReceived(self, data):
-    #print('IPIF-GOT ', repr(data))
-    self._buffer += data
-    packets = slip.decode(self._buffer)
-    self._buffer = packets.pop()
-    for packet in packets:
-      if not len(packet): continue
-      (saddr, daddr) = packet_addrs(packet)
-      if saddr.is_link_local or daddr.is_link_local:
-        log_discard(packet, saddr, daddr, 'link-local')
-        continue
-      self._router(packet, saddr, daddr)
+    self._decoder.inputdata(data)
+  def slip_on_packet(self, packet):
+    (saddr, daddr) = packet_addrs(packet)
+    if saddr.is_link_local or daddr.is_link_local:
+      log_discard(packet, 'ipif', saddr, daddr, 'link-local')
+      return
+    self._router(packet, saddr, daddr)
   def processEnded(self, status):
     status.raiseException()
 
@@ -141,9 +208,11 @@ def start_ipif(command, router):
   ipif = _IpifProcessProtocol(router)
   reactor.spawnProcess(ipif,
                        '/bin/sh',['sh','-xc', command],
-                       childFDs={0:'w', 1:'r', 2:2})
+                       childFDs={0:'w', 1:'r', 2:2},
+                       env=None)
 
 def queue_inbound(packet):
+  log_debug(DBG.FLOW, "queue_inbound", d=packet)
   ipif.transport.write(slip.delimiter)
   ipif.transport.write(slip.encode(packet))
   ipif.transport.write(slip.delimiter)
@@ -151,36 +220,74 @@ def queue_inbound(packet):
 #---------- packet queue ----------
 
 class PacketQueue():
-  def __init__(self, max_queue_time):
+  def __init__(self, desc, max_queue_time):
+    self._desc = desc
+    assert(desc + '')
     self._max_queue_time = max_queue_time
     self._pq = collections.deque() # packets
 
+  def _log(self, dflag, msg, **kwargs):
+    log_debug(dflag, self._desc+' pq: '+msg, **kwargs)
+
   def append(self, packet):
+    self._log(DBG.QUEUE, 'append', d=packet)
     self._pq.append((time.monotonic(), packet))
 
   def nonempty(self):
+    self._log(DBG.QUEUE, 'nonempty ?')
     while True:
       try: (queuetime, packet) = self._pq[0]
-      except IndexError: return False
+      except IndexError:
+        self._log(DBG.QUEUE, 'nonempty ? empty.')
+        return False
 
       age = time.monotonic() - queuetime
-      if age > self.max_queue_time:
+      if age > self._max_queue_time:
         # strip old packets off the front
+        self._log(DBG.QUEUE, 'dropping (old)', d=packet)
         self._pq.popleft()
         continue
 
+      self._log(DBG.QUEUE, 'nonempty ? nonempty.')
       return True
 
-  def popleft(self):
-    # caller must have checked nonempty
-    try: (dummy, packet) = self._pq[0]
-    except IndexError: return None
-    return packet
+  def process(self, sizequery, moredata, max_batch):
+    # sizequery() should return size of batch so far
+    # moredata(s) should add s to batch
+    self._log(DBG.QUEUE, 'process...')
+    while True:
+      try: (dummy, packet) = self._pq[0]
+      except IndexError:
+        self._log(DBG.QUEUE, 'process... empty')
+        break
+
+      self._log(DBG.QUEUE_CTRL, 'process... packet', d=packet)
+
+      encoded = slip.encode(packet)
+      sofar = sizequery()  
+
+      self._log(DBG.QUEUE_CTRL,
+                'process... (sofar=%d, max=%d) encoded' % (sofar, max_batch),
+                d=encoded)
+
+      if sofar > 0:
+        if sofar + len(slip.delimiter) + len(encoded) > max_batch:
+          self._log(DBG.QUEUE_CTRL, 'process... overflow')
+          break
+        moredata(slip.delimiter)
+
+      moredata(encoded)
+      self._pq.popleft()
 
 #---------- error handling ----------
 
+_crashing = False
+
 def crash(err):
-  print('CRASH ', err, file=sys.stderr)
+  global _crashing
+  _crashing = True
+  print('========== CRASH ==========', err,
+        '===========================', file=sys.stderr)
   try: reactor.stop()
   except twisted.internet.error.ReactorNotRunning: pass
 
@@ -203,7 +310,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__)
 
@@ -226,17 +333,17 @@ class ServerAddr():
     try:
       self.addr = ipaddress.IPv4Address(addrspec)
       self._endpointfactory = twisted.internet.endpoints.TCP4ServerEndpoint
-      self._inurl = '%s'
+      self._inurl = b'%s'
     except AddressValueError:
       self.addr = ipaddress.IPv6Address(addrspec)
       self._endpointfactory = twisted.internet.endpoints.TCP6ServerEndpoint
-      self._inurl = '[%s]'
+      self._inurl = b'[%s]'
   def make_endpoint(self):
     return self._endpointfactory(reactor, self.port, self.addr)
   def url(self):
-    url = 'http://' + (self._inurl % self.addr)
-    if self.port != 80: url += ':%d' % self.port
-    url += '/'
+    url = b'http://' + (self._inurl % str(self.addr).encode('ascii'))
+    if self.port != 80: url += b':%d' % self.port
+    url += b'/'
     return url
     
 def process_cfg_saddrs():
@@ -254,12 +361,17 @@ def process_cfg_clients(constructor):
     if not (':' in cs or '.' in cs): continue
     ci = ipaddr(cs)
     pw = cfg.get(cs, 'password')
+    pw = pw.encode('utf-8')
     constructor(ci,cs,pw)
 
 #---------- startup ----------
 
 def common_startup():
-  twisted.logger.globalLogPublisher.addObserver(crash_on_critical)
+  log_formatter = twisted.logger.formatEventAsClassicLogText
+  log_observer = twisted.logger.FileLogObserver(sys.stderr, log_formatter)
+  twisted.logger.globalLogBeginner.beginLoggingTo(
+    [ log_observer, crash_on_critical ]
+    )
 
   optparser.add_option('-c', '--config', dest='configfile',
                        default='/etc/hippotat/config')
@@ -271,5 +383,6 @@ def common_startup():
   cfg.read(opts.configfile)
 
 def common_run():
-  reactor.run()
+  log_debug(DBG.INIT, 'entering reactor')
+  if not _crashing: reactor.run()
   print('CRASHED (end)', file=sys.stderr)