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
from configparser import ConfigParser
from configparser import NoOptionError
+from functools import partial
+
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
max_batch_down = 65536 # used by server, subject to [limits]
max_queue_time = 10 # used by server, subject to [limits]
-max_request_time = 54 # used by server, subject to [limits]
target_requests_outstanding = 3 # must match; subject to [limits] on server
+http_timeout = 30 # used by both } must be
+http_timeout_grace = 5 # used by both } compatible
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
[limits]
max_batch_down = 262144 # used by server
max_queue_time = 121 # used by server
-max_request_time = 121 # used by server
+http_timeout = 121 # used by server
target_requests_outstanding = 10 # used by server
'''
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 ----------
#---------- ipif (SLIP) subprocess ----------
class SlipStreamDecoder():
- def __init__(self, on_packet):
- # we will call packet(<packet>)
+ 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):
- #print('SLIP-GOT ', repr(data))
- self._buffer += data
- packets = slip.decode(self._buffer)
+ self._log('inputdata', d=data)
+ packets = slip.decode(data)
+ packets[0] = self._buffer + packets[0]
self._buffer = packets.pop()
for packet in packets:
self._maybe_packet(packet)
+ self._log('bufremain', d=self._buffer)
def _maybe_packet(self, packet):
- if len(packet):
- self._on_packet(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._router = router
- self._decoder = SlipStreamDecoder(self.slip_on_packet)
+ self._decoder = SlipStreamDecoder('ipif', self.slip_on_packet)
def connectionMade(self): pass
def outReceived(self, data):
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, saddr, daddr, 'link-local')
+ log_discard(packet, 'ipif', saddr, daddr, 'link-local')
return
self._router(packet, saddr, daddr)
def processEnded(self, status):
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)
#---------- 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:
# 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 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: break
+ 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)
#---------- 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
except AttributeError: continue
setattr(c, d, v)
- print(repr(c))
+ #print(repr(c))
c.ipif_command = cfg.get(section,'ipif', vars=c.__dict__)
#---------- 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')
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)
~ian / hippotat.git / blobdiff