From: Ian Jackson <ijackson@chiark.greenend.org.uk>
Date: Wed, 29 Mar 2017 20:45:48 +0000 (+0100)
Subject: wip, before optional args log_xxx
X-Git-Tag: hippotat/1.0.0~55^2~196
X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ian/git?p=hippotat.git;a=commitdiff_plain;h=d579a04817c1a141e715481a18fe7d71568c451d

wip, before optional args log_xxx
---

diff --git a/hippotat/__init__.py b/hippotat/__init__.py
index 9bfe280..abc2a9f 100644
--- a/hippotat/__init__.py
+++ b/hippotat/__init__.py
@@ -22,8 +22,19 @@ import time
 
 import re as regexp
 
+from twisted.python.constants import NamedConstant
+
 import hippotat.slip as slip
 
+class DBG(twisted.python.constants.Names):
+  ROUTE = NamedConstant()
+  FLOW = NamedConstant()
+  HTTP = NamedConstant()
+  HTTP_CTRL = NamedConstant()
+  INIT = NamedConstant()
+  QUEUE = NamedConstant()
+  QUEUE_CTRL = NamedConstant()
+
 defcfg = '''
 [DEFAULT]
 #[<client>] overrides
@@ -179,14 +190,20 @@ def queue_inbound(packet):
 #---------- packet queue ----------
 
 class PacketQueue():
-  def __init__(self, max_queue_time):
+  def __init__(self, desc, max_queue_time):
+    self._desc = desc
     self._max_queue_time = max_queue_time
     self._pq = collections.deque() # packets
 
+  def _log_debug(self, fn, pri, msg)
+    log_debug(pri, 
+
   def append(self, packet):
+    log_data(DBG.QUEUE, packet, 'pq %s: append' % self._desc)
     self._pq.append((time.monotonic(), packet))
 
   def nonempty(self):
+    log_debug(DBG.QUEUE, 'pq %s: nonempty ?' % self._desc)
     while True:
       try: (queuetime, packet) = self._pq[0]
       except IndexError: return False
diff --git a/server b/server
index 1b43fb0..68a3ebd 100755
--- a/server
+++ b/server
@@ -17,18 +17,22 @@ clients = { }
 #---------- "router" ----------
 
 def route(packet, saddr, daddr):
-  print('TRACE ', saddr, daddr, packet)
+  def lt(dest):
+    log_data(DBG.ROUTE, packet, 'route: %s -> %s: %s' % (saddr,daddr,dest))
   try: dclient = clients[daddr]
   except KeyError: dclient = None
   if dclient is not None:
+    lt('client')
     dclient.queue_outbound(packet)
   elif daddr == c.server or daddr not in c.network:
-    print('TRACE INBOUND ', saddr, daddr, packet)
+    lt('inbound')
     queue_inbound(packet)
   elif daddr == relay:
+    lt('discard relay')
     log_discard(packet, saddr, daddr, 'relay')
   else:
-    log_discard(packet, saddr, daddr, 'no client')
+    lt('discard no-client')
+    log_discard(packet, saddr, daddr, 'no-client')
 
 #---------- client ----------
 
@@ -61,7 +65,10 @@ class Client():
       raise ValueError('multiple client cfg sections for %s' % ip)
     clients[ip] = self
 
+    log_debug('DBG.INIT', 'new client %s' % self)
+
   def process_arriving_data(self, d):
+    log_data(DBG.FLOW, d, 'client req data: %s' % saddr=self._ip)
     for packet in slip.decode(d):
       (saddr, daddr) = packet_addrs(packet)
       if saddr != self._ip:
@@ -69,16 +76,18 @@ class Client():
       route(packet, saddr, daddr)
 
   def _req_cancel(self, request):
+    log_httpreq(DBG.HTTPCTRL, request, 'cancel')
     request.finish()
 
   def _req_error(self, err, request):
+    log_httpreq(DBG.HTTPCTRL, request, 'error %s' % err)
     self._req_cancel(request)
 
   def queue_outbound(self, packet):
     self._pq.append(packet)
     self._check_outbound()
 
-  def http_request(self, request):
+  def new_request(self, request):
     request.setHeader('Content-Type','application/octet-stream')
     reactor.callLater(self.max_request_time, self._req_cancel, request)
     request.notifyFinish().addErrback(self._req_error, request)
@@ -86,21 +95,26 @@ class Client():
     self._check_outbound()
 
   def _check_outbound(self):
+    log_httpreq(DBG.HTTPCTRL, None, '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._rq.popleft()
         continue
 
       if not self._pq.nonempty():
         # no packets, oh well
-        continue
+        log_httpreq(DBG.HTTP_CTRL, request, 'CHKO no packets, OUT-DONE')
+        break
 
       if request is None:
         # no request
+        log_httpreq(DBG.HTTP_CTRL, request, 'CHKO no request, OUT-DONE')
         break
 
+      log_httpreq(DBG.HTTP_CTRL, request, 'CHKO processing')
       # request, and also some non-expired packets
       self._pq.process((lambda: request.sentLength),
                        request.write,
@@ -109,24 +123,32 @@ class Client():
       assert(request.sentLength)
       self._rq.popleft()
       request.finish()
+      log_httpreq(DBG.HTTP, request, 'complete')
       # 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')
       request.finish()
 
-def process_request(request):
+def process_request(request, desca):
   # find client, update config, etc.
   metadata = request.args['m']
+  metadata = metadata.split(b'\n')
   (ci_s, pw, tro) = metadata.split(b'\n')[0:3]
+  desca['m'] = [ci_s, tro]
   ci = ipaddr(ci_s)
+  desca['ci'] = ci
   cl = clients[ci]
   if pw != cl.pw: raise ValueError('bad password')
+  desca['pwok'=True]
 
-  if pw != cl.target_requests_outstanding:
-    raise ...
+  if tro != cl.target_requests_outstanding:
+    raise ValueError('tro must be %d' % cl.target_requests_outstanding)
 
-  try: d = request.args['d']
+  try:
+    d = request.args['d']
+    desca['d'] = d
   except KeyError: d = ''
 
   cl.process_arriving_data(d)
@@ -135,13 +157,19 @@ def process_request(request):
 class IphttpResource(twisted.web.resource.Resource):
   isLeaf = True
   def render_POST(self, request):
-    try: process_request(request)
+    desca = {'d': None}
+    try: process_request(request, desca)
     except Exception as e:
+      emsg = str(e).encode('utf-8')
+      log_http(desca, 'EXCEPTION ' + emsg)
       request.setHeader('Content-Type','text/plain; charset="utf-8"')
       request.setResponseCode(400)
-      return str(e).encode('utf-8')
+      return emsg
+    log_http(desca, '... [%s]' % id(request))
+    return NOT_DONE_YET
 
   def render_GET(self, request):
+    log_debug(DBG.HTTP, 'GET request')
     return b'<html><body>hippotat</body></html>'
 
 def start_http():
@@ -150,6 +178,7 @@ def start_http():
   for sa in c.saddrs:
     ep = sa.make_endpoint()
     crash_on_defer(ep.listen(site))
+    log_debug(DBG.INIT, 'listening on %s' % sa)
 
 #---------- config and setup ----------