X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ian/git?p=hippotat.git;a=blobdiff_plain;f=hippotat%2F__init__.py;h=d8b119a2b5c70d345605231dc6e2e2920dbfba8d;hp=194dc9971bd7b3ede7573ae720e76c374b5f04e0;hb=7432045dad21ff8ee05d071dd24094280b911a5e;hpb=1d023c89e4379225b5d71e565b93f537e119ab75 diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 194dc99..d8b119a 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -3,26 +3,147 @@ import signal signal.signal(signal.SIGINT, signal.SIG_DFL) +import sys + +from zope.interface import implementer + 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 -import hippotat.slip as slip - from optparse import OptionParser 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): + INIT = NamedConstant() + ROUTE = NamedConstant() + DROP = NamedConstant() + FLOW = NamedConstant() + HTTP = NamedConstant() + TWISTED = NamedConstant() + QUEUE = NamedConstant() + HTTP_CTRL = NamedConstant() + QUEUE_CTRL = NamedConstant() + HTTP_FULL = NamedConstant() + CTRL_DUMP = NamedConstant() + SLIP_FULL = NamedConstant() + DATA_COMPLETE = NamedConstant() + +_hex_codec = codecs.getencoder('hex_codec') + +#---------- logging ---------- + +org_stderr = sys.stderr + +log = twisted.logger.Logger() + +debug_set = set() +debug_def_detail = DBG.HTTP + +def log_debug(dflag, msg, idof=None, d=None): + if dflag not in debug_set: return + #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: + trunc = '' + if not DBG.DATA_COMPLETE in debug_set: + if len(d) > 64: + d = d[0:64] + trunc = '...' + d = _hex_codec(d)[0].decode('ascii') + msg += ' ' + d + trunc + log.info('{dflag} {msgcore}', dflag=dflag, msgcore=msg) + +@implementer(twisted.logger.ILogFilterPredicate) +class LogNotBoringTwisted: + def __call__(self, event): + yes = twisted.logger.PredicateResult.yes + no = twisted.logger.PredicateResult.no + try: + if event.get('log_level') != LogLevel.info: + return yes + dflag = event.get('dflag') + if dflag in debug_set: return yes + if dflag is None and DBG.TWISTED in debug_set: return yes + return no + except Exception: + print(traceback.format_exc(), file=org_stderr) + return yes + +#---------- default config ---------- + +defcfg = ''' +[DEFAULT] +#[] overrides +max_batch_down = 65536 # used by server, subject to [limits] +max_queue_time = 10 # 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_retry = 5 # used by client + +#[server] or [] overrides +ipif = userv root ipif %(local)s,%(peer)s,%(mtu)s,slip %(rnets)s +# extra interpolations: %(local)s %(peer)s %(rnet)s +# obtained on server [virtual]server [virtual]relay [virtual]network +# from on client [virtual]server [virtual]routes + +[virtual] +mtu = 1500 +routes = '' +# network = / # mandatory for server +# server = # used by both, default is computed from `network' +# relay = # used by server, default from `network' and `server' +# default server is first host in network +# default relay is first host which is not server + +[server] +# addrs = 127.0.0.1 ::1 # mandatory for server +port = 80 # used by server +# url # used by client; default from first `addrs' and `port' + +# [] +# password = # used by both, must match + +[limits] +max_batch_down = 262144 # used by server +max_queue_time = 121 # used by server +http_timeout = 121 # used by server +target_requests_outstanding = 10 # used by server +''' # these need to be defined here so that they can be imported by import * 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 @@ -31,6 +152,11 @@ class ConfigResults: c = ConfigResults() +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 ---------- def packet_addrs(packet): @@ -67,20 +193,48 @@ 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) + 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): + 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('RECV ', 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) - 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() @@ -89,9 +243,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) @@ -99,36 +255,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 @@ -148,10 +342,10 @@ def process_cfg_common_always(): def process_cfg_ipif(section, varmap): for d, s in varmap: try: v = getattr(c, s) - except KeyError: pass + except AttributeError: continue setattr(c, d, v) - print(repr(c)) + #print(repr(c)) c.ipif_command = cfg.get(section,'ipif', vars=c.__dict__) @@ -174,17 +368,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(): @@ -202,21 +396,94 @@ 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(defcfg): - twisted.logger.globalLogPublisher.addObserver(crash_on_critical) - +def common_startup(): optparser.add_option('-c', '--config', dest='configfile', default='/etc/hippotat/config') + + def dfs_less_detailed(dl): + return [df for df in DBG.iterconstants() if df <= dl] + + def ds_default(od,os,dl,op): + global debug_set + debug_set = set(dfs_less_detailed(debug_def_detail)) + + def ds_select(od,os, spec, op): + for it in spec.split(','): + + if it.startswith('-'): + mutator = debug_set.discard + it = it[1:] + else: + mutator = debug_set.add + + if it == '+': + dfs = DBG.iterconstants() + + else: + if it.endswith('+'): + mapper = dfs_less_detailed + it = it[0:len(it)-1] + else: + mapper = lambda x: [x] + + try: + dfspec = DBG.lookupByName(it) + except ValueError: + optparser.error('unknown debug flag %s in --debug-select' % it) + + dfs = mapper(dfspec) + + for df in dfs: + mutator(df) + + optparser.add_option('-D', '--debug', + nargs=0, + action='callback', + help='enable default debug (to stdout)', + callback= ds_default) + + optparser.add_option('--debug-select', + nargs=1, + type='string', + metavar='[-]DFLAG[+]|[-]+,...', + help= +'''enable (`-': disable) each specified DFLAG; +`+': do same for all "more interesting" DFLAGSs; +just `+': all DFLAGs. + DFLAGS: ''' + ' '.join([df.name for df in DBG.iterconstants()]), + action='callback', + callback= ds_select) + (opts, args) = optparser.parse_args() if len(args): optparser.error('no non-option arguments please') - cfg.read_string(defcfg) + #print(repr(debug_set), file=sys.stderr) + + re = regexp.compile('#.*') + cfg.read_string(re.sub('', defcfg)) cfg.read(opts.configfile) + log_formatter = twisted.logger.formatEventAsClassicLogText + stdout_obs = twisted.logger.FileLogObserver(sys.stdout, log_formatter) + stderr_obs = twisted.logger.FileLogObserver(sys.stderr, log_formatter) + pred = twisted.logger.LogLevelFilterPredicate(LogLevel.error) + stdsomething_obs = twisted.logger.FilteringLogObserver( + stderr_obs, [pred], stdout_obs + ) + log_observer = twisted.logger.FilteringLogObserver( + stdsomething_obs, [LogNotBoringTwisted()] + ) + #log_observer = stdsomething_obs + twisted.logger.globalLogBeginner.beginLoggingTo( + [ log_observer, crash_on_critical ] + ) + def common_run(): - reactor.run() + log_debug(DBG.INIT, 'entering reactor') + if not _crashing: reactor.run() print('CRASHED (end)', file=sys.stderr)