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 collections
import time
+import codecs
import re as regexp
-from twisted.python.constants import NamedConstant
-
import hippotat.slip as slip
class DBG(twisted.python.constants.Names):
QUEUE = NamedConstant()
QUEUE_CTRL = NamedConstant()
+_hexcodec = codecs.getencoder('hex_codec')
+
+log = twisted.logger.Logger()
+
+def log_debug(dflag, msg, idof=None, d=None):
+ if idof is not None:
+ msg = '[%d] %s' % (id(idof), msg)
+ if d is not None:
+ d = d[0:64]
+ d = _hex_codec(d)[0]
+ msg += ' ' + d
+ log.info('{dflag} {msgcore}', dflag=dflag, msgcore=msg)
+
defcfg = '''
[DEFAULT]
#[<client>] overrides
c = ConfigResults()
def log_discard(packet, saddr, daddr, why):
- print('DROP ', saddr, daddr, why)
+
+ Print('Drop ', Saddr, Daddr, why)
# syslog.syslog(syslog.LOG_DEBUG,
# 'discarded packet %s -> %s (%s)' % (saddr, daddr, why))
self._max_queue_time = max_queue_time
self._pq = collections.deque() # packets
- def _log_debug(self, fn, pri, msg)
- log_debug(pri,
+ def _log(self, dflag, msg, **kwargs)
+ log_debug(dflag, self._desc+' pq: '+msg, **kwargs)
def append(self, packet):
- log_data(DBG.QUEUE, packet, 'pq %s: append' % self._desc)
+ self._log(DBG.QUEUE, 'append', d=packet)
self._pq.append((time.monotonic(), packet))
def nonempty(self):
- log_debug(DBG.QUEUE, 'pq %s: nonempty ?' % self._desc)
+ 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)
#---------- 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():
+ log_debug(DBG.INIT, 'ready')
reactor.run()
print('CRASHED (end)', file=sys.stderr)
def route(packet, saddr, daddr):
def lt(dest):
- log_data(DBG.ROUTE, packet, 'route: %s -> %s: %s' % (saddr,daddr,dest))
+ log_debug(DBG.ROUTE, 'route: %s -> %s: %s' % (saddr,daddr,dest), d=packet)
try: dclient = clients[daddr]
except KeyError: dclient = None
if dclient is not None:
limit = cfg.getint('limits',k)
self.__dict__[k] = min(req, limit)
- self._pq = PacketQueue(self.max_queue_time)
+ self._pq = PacketQueue(ip, self.max_queue_time)
if ip in clients:
raise ValueError('multiple client cfg sections for %s' % ip)
clients[ip] = self
- log_debug('DBG.INIT', 'new client %s' % self)
+ self._log(DBG.INIT, 'new')
+
+ def _log(self, pri, msg, **kwargs):
+ log_debug(pri, 'client '+self._ip+': '+msg, **kwargs)
def process_arriving_data(self, d):
- log_data(DBG.FLOW, d, 'client req data: %s' % saddr=self._ip)
+ self._log(DBG.FLOW, 'req data', d=d)
for packet in slip.decode(d):
(saddr, daddr) = packet_addrs(packet)
if saddr != self._ip:
route(packet, saddr, daddr)
def _req_cancel(self, request):
- log_httpreq(DBG.HTTPCTRL, request, 'cancel')
+ self._log(DBG.HTTPCTRL, 'cancel', idof=request)
request.finish()
def _req_error(self, err, request):
- log_httpreq(DBG.HTTPCTRL, request, 'error %s' % err)
+ self._log(DBG.HTTPCTRL, 'error %s' % err, idof=request)
self._req_cancel(request)
def queue_outbound(self, packet):
self._check_outbound()
def _check_outbound(self):
- log_httpreq(DBG.HTTPCTRL, None, 'CHKO')
+ log_debug(DBG.HTTPCTRL, 'CHKO')
while True:
try: request = self._rq[0]
except IndexError: request = None
if request and request.finished:
- log_httpreq(DBG.HTTP_CTRL, request, 'CHKO request finished, discard')
+ self._log(DBG.HTTP_CTRL, 'CHKO req finished, discard', idof=request)
self._rq.popleft()
continue
if not self._pq.nonempty():
# no packets, oh well
- log_httpreq(DBG.HTTP_CTRL, request, 'CHKO no packets, OUT-DONE')
+ self._log(DBG.HTTP_CTRL, 'CHKO no packets, OUT-DONE', idof=request)
break
if request is None:
# no request
- log_httpreq(DBG.HTTP_CTRL, request, 'CHKO no request, OUT-DONE')
+ self._log(DBG.HTTP_CTRL, 'CHKO no request, OUT-DONE', idof=request)
break
- log_httpreq(DBG.HTTP_CTRL, request, 'CHKO processing')
+ self._log(DBG.HTTP_CTRL, 'CHKO processing', idof=request)
# request, and also some non-expired packets
self._pq.process((lambda: request.sentLength),
request.write,
assert(request.sentLength)
self._rq.popleft()
request.finish()
- log_httpreq(DBG.HTTP, request, 'complete')
+ self._log(DBG.HTTP, 'complete', idof=request)
# round again, looking for more to do
while len(self._rq) > self.target_requests_outstanding:
request = self._rq.popleft()
- log_httpreq(DBG.HTTP, request, 'CHKO above target, returning empty')
+ self._log(DBG.HTTP, 'CHKO above target, returning empty', idof=request)
request.finish()
def process_request(request, desca):
cl.process_arriving_data(d)
cl.new_request(request)
+def log_http(desca, msg):
+ try:
+ d = desca['d']
+ del desca['d']
+ except KeyError:
+ d = None
+ log_debug(DBG.HTTP, msg + repr(desca), d=d)
+
class IphttpResource(twisted.web.resource.Resource):
isLeaf = True
def render_POST(self, request):