From 47191df1e45fed6fc6ec1c37f741a4a6a8588671 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:13:37 +0100 Subject: [PATCH 01/16] wip, towards target --- client | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) diff --git a/client b/client index 6442154..c08b5fc 100755 --- a/client +++ b/client @@ -104,15 +104,11 @@ def req_err(req, err): reactor.callLater(c.http_retry, (lambda: req_fin(req))) def req_fin(req): + log_debug(DBG.HTTP_CTRL, 'req_fin', idof=req) global outstanding outstanding -= 1 check_outbound() -def asyncfailure(reason): - global outstanding - outstanding += 1 - req_err(None, reason) - def check_outbound(): global outstanding @@ -162,6 +158,8 @@ def check_outbound(): c.url, twisted.web.client.Headers(hh), producer) + + log_debug(DBG.HTTP_CTRL, 'request', idof=req, d=d) req.addTimeout(c.http_timeout, reactor) req.addCallback((lambda resp: req_ok(req, resp))) req.addErrback((lambda err: req_err(req, err))) -- 2.30.2 From f7ec639f73a3d6fcd5285507901e353cdb25fc29 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:17:10 +0100 Subject: [PATCH 02/16] wip --- fake-userv | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/fake-userv b/fake-userv index 0796412..1678fae 100755 --- a/fake-userv +++ b/fake-userv @@ -2,7 +2,7 @@ set -ex echo >&2 "$0: invoked as $0 $*" exec 3<&0 4>&1 5>&2 >&2 &4 2>&5 & sleep 0.1 env - bash -i -- 2.30.2 From 5dd3275bb14a49afe8e2d9571755d22164c59a2f Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:24:02 +0100 Subject: [PATCH 03/16] wip --- client | 12 +++++++++++- server | 2 +- 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/client b/client index c08b5fc..ec28fd0 100755 --- a/client +++ b/client @@ -93,7 +93,17 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): req_err(self._req, reason) def req_ok(req, resp): - log_debug(DBG.HTTP_CTRL, 'req_ok ' + str(resp), idof=req) + log_debug(DBG.HTTP_CTRL, + 'req_ok %d %s %s' % (resp.code, repr(resp.phrase), str(resp)), + idof=req) + if resp.code != 200: + try: + phrase = resp.phrase.decode('utf-8') + except UnicodeDecodeError: + phrase = repr(resp.phrase) + req_err(req, "FAILED %d %s" % (resp.code, phrase)) + return + rc = ResponseConsumer(req) resp.deliverBody(rc) req_fin(req) diff --git a/server b/server index 79bd15b..6a71bfd 100755 --- a/server +++ b/server @@ -139,7 +139,7 @@ class Client(): def process_request(request, desca): # find client, update config, etc. - metadata = request.args[b'mX'][0] + metadata = request.args[b'm'][0] metadata = metadata.split(b'\r\n') (ci_s, pw, tro) = metadata[0:3] desca['m[0,2]'] = [ci_s, tro] -- 2.30.2 From 6e4af0a263956f059c0a352c382c17e6098ff861 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:33:52 +0100 Subject: [PATCH 04/16] wip --- client | 47 +++++++++++++++++++++++++++++++++-------------- 1 file changed, 33 insertions(+), 14 deletions(-) diff --git a/client b/client index ec28fd0..cda0ac8 100755 --- a/client +++ b/client @@ -88,25 +88,44 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): def _asyncfailure(self, reason): self._log(DBG.HTTP_CTRL, '_asyncFailure ' + str(reason)) - global outstanding - outstanding += 1 req_err(self._req, reason) +class ErrorResponseConsumer(twisted.internet.protocol.Protocol): + def __init__(self, req, resp): + self._req = req + self._resp = resp + + try: + self._phrase = resp.phrase.decode('utf-8') + except Exception: + self._phrase = repr(resp.phrase) + + self._log(DBG.HTTP_CTRL, '__init__ %d %s' % (resp.code, self._phrase)) + + def _log(self, dflag, msg, **kwargs): + log_debug(dflag,'ERROR-RC '+msg, idof=self._req, **kwargs) + + def connectionMade(self): self._m = '' + def dataReceived(self, data): self._m += data + def connectionLost(self, reason): + try: + mbody = self._m.decode('utf-8') + except Exception: + mbody = repr(self._m) + req_err(req, + "FAILED %d %s | %s | %s" + % (self._resp.code, self.phrase, mbody, str(reason))) + def req_ok(req, resp): log_debug(DBG.HTTP_CTRL, 'req_ok %d %s %s' % (resp.code, repr(resp.phrase), str(resp)), idof=req) - if resp.code != 200: - try: - phrase = resp.phrase.decode('utf-8') - except UnicodeDecodeError: - phrase = repr(resp.phrase) - req_err(req, "FAILED %d %s" % (resp.code, phrase)) - return + if resp.code == 200: + rc = ResponseConsumer(req) + else: + rc = ErrorResponseConsumer(req, resp) - rc = ResponseConsumer(req) resp.deliverBody(rc) - req_fin(req) def req_err(req, err): log_debug(DBG.HTTP_CTRL, 'req_err ' + str(err), idof=req) @@ -114,9 +133,9 @@ def req_err(req, err): reactor.callLater(c.http_retry, (lambda: req_fin(req))) def req_fin(req): - log_debug(DBG.HTTP_CTRL, 'req_fin', idof=req) global outstanding outstanding -= 1 + log_debug(DBG.HTTP_CTRL, 'req_fin OS=%d' % outstanding, idof=req) check_outbound() def check_outbound(): @@ -169,11 +188,11 @@ def check_outbound(): twisted.web.client.Headers(hh), producer) - log_debug(DBG.HTTP_CTRL, 'request', idof=req, d=d) + outstanding += 1 + log_debug(DBG.HTTP_CTRL, 'request OS=%d' % outstanding, idof=req, d=d) req.addTimeout(c.http_timeout, reactor) req.addCallback((lambda resp: req_ok(req, resp))) req.addErrback((lambda err: req_err(req, err))) - outstanding += 1 common_startup() process_cfg() -- 2.30.2 From 765aba5533468aa9fdae4dea4ebf3e34f1fc2605 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:40:42 +0100 Subject: [PATCH 05/16] wip --- client | 28 ++++++++++++++++++---------- 1 file changed, 18 insertions(+), 10 deletions(-) diff --git a/client b/client index cda0ac8..9ed719e 100755 --- a/client +++ b/client @@ -79,12 +79,13 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): def connectionLost(self, reason): self._log(DBG.HTTP_CTRL, 'connectionLost ' + str(reason)) - if reason.check(twisted.web.client.ResponseDone): - try: self._ssd.flush() - except Exception as e: - self._asyncfailure(e) - else: + if not reason.check(twisted.web.client.ResponseDone): self._asyncfailure(reason) + return + try: + self._ssd.flush() + except Exception as e: + self._asyncfailure(e) def _asyncfailure(self, reason): self._log(DBG.HTTP_CTRL, '_asyncFailure ' + str(reason)) @@ -105,16 +106,23 @@ class ErrorResponseConsumer(twisted.internet.protocol.Protocol): def _log(self, dflag, msg, **kwargs): log_debug(dflag,'ERROR-RC '+msg, idof=self._req, **kwargs) - def connectionMade(self): self._m = '' - def dataReceived(self, data): self._m += data + def connectionMade(self): + self._m = b'' + + def dataReceived(self, data): + self._log(DBG.HTTP_CTRL, 'dataReceived ' + repr(data)) + self._m += data + def connectionLost(self, reason): try: mbody = self._m.decode('utf-8') except Exception: mbody = repr(self._m) - req_err(req, - "FAILED %d %s | %s | %s" - % (self._resp.code, self.phrase, mbody, str(reason))) + if not reason.check(twisted.web.client.ResponseDone): + mbody += ' || ' + str(reason) + req_err(self._req, + "FAILED %d %s | %s" + % (self._resp.code, self._phrase, mbody)) def req_ok(req, resp): log_debug(DBG.HTTP_CTRL, -- 2.30.2 From d7b4e25b928804b0ae940988dcc097dd3d23c40c Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 21:46:32 +0100 Subject: [PATCH 06/16] wip --- client | 2 ++ 1 file changed, 2 insertions(+) diff --git a/client b/client index 9ed719e..543d2f5 100755 --- a/client +++ b/client @@ -137,6 +137,8 @@ def req_ok(req, resp): def req_err(req, err): log_debug(DBG.HTTP_CTRL, 'req_err ' + str(err), idof=req) + if isinstance(err, twisted.python.failure.Failure): + err = err.getTraceback() print(err, file=sys.stderr) reactor.callLater(c.http_retry, (lambda: req_fin(req))) -- 2.30.2 From 19f5f9b5e629954e3917cb8fa47506145c04fb28 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 22:25:35 +0100 Subject: [PATCH 07/16] wip --- server | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/server b/server index 6a71bfd..3bfbc42 100755 --- a/server +++ b/server @@ -158,18 +158,23 @@ def process_request(request, desca): try: d = request.args[b'd'][0] desca['d'] = d - except KeyError: d = b'' + desca['dlen'] = len(d) + except KeyError: + d = b'' + desca['dlen'] = None + + log_http(desca, 'processing', idof=id(request), d=d) cl.process_arriving_data(d) cl.new_request(request) -def log_http(desca, msg): +def log_http(desca, msg, **kwargs): try: - d = desca['d'] + kwargs['d'] = desca['d'] del desca['d'] except KeyError: - d = None - log_debug(DBG.HTTP, msg + repr(desca), d=d) + pass + log_debug(DBG.HTTP, msg + repr(desca), **kwargs) class IphttpResource(twisted.web.resource.Resource): isLeaf = True @@ -185,7 +190,7 @@ class IphttpResource(twisted.web.resource.Resource): request.setHeader('Content-Type','text/plain; charset="utf-8"') request.setResponseCode(400) return (emsg + ' # ' + repr(desca) + '\r\n').encode('utf-8') - log_http(desca, '... [%s]' % id(request)) + log_debug(DBG.HTTP_CTRL, '...', idof=id(request)) return NOT_DONE_YET def render_GET(self, request): -- 2.30.2 From 6f387df3234541f1066eff163d18fa6becf59c82 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 22:35:08 +0100 Subject: [PATCH 08/16] wip, progress! --- hippotat/slip.py | 2 +- server | 6 ++++-- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/hippotat/slip.py b/hippotat/slip.py index e339f69..f135137 100644 --- a/hippotat/slip.py +++ b/hippotat/slip.py @@ -12,7 +12,7 @@ def encode(packet): .replace(end, esc + esc_end)) def decode(data): - print('DECODE ', repr(data)) + #print('DECODE ', repr(data)) out = [] for packet in data.split(end): pdata = b'' diff --git a/server b/server index 3bfbc42..e5aa67b 100755 --- a/server +++ b/server @@ -165,6 +165,8 @@ def process_request(request, desca): log_http(desca, 'processing', idof=id(request), d=d) + d = mime_translate(d) + cl.process_arriving_data(d) cl.new_request(request) @@ -186,7 +188,7 @@ class IphttpResource(twisted.web.resource.Resource): try: process_request(request, desca) except Exception as e: emsg = traceback.format_exc() - log_http(desca, 'EXCEPTION ' + emsg) + log_http(desca, 'RETURNING EXCEPTION ' + emsg) request.setHeader('Content-Type','text/plain; charset="utf-8"') request.setResponseCode(400) return (emsg + ' # ' + repr(desca) + '\r\n').encode('utf-8') @@ -230,6 +232,6 @@ def process_cfg(): common_startup() process_cfg() -start_ipif(c.ipif_command, route) +start_ipif(c.ipif_command, (lambda p,s,d: route(p,"[ipif]",s,d))) start_http() common_run() -- 2.30.2 From eedc8b30ac92c216d6eef8ff9616bc0cf226a8e6 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 22:52:38 +0100 Subject: [PATCH 09/16] wip, fixes --- client | 11 ++++++++--- hippotat/__init__.py | 1 + server | 2 -- 3 files changed, 9 insertions(+), 5 deletions(-) diff --git a/client b/client index 543d2f5..b5a4db5 100755 --- a/client +++ b/client @@ -58,10 +58,12 @@ def outbound(packet, saddr, daddr): queue.append(packet) check_outbound() +def crashy(): assert(False) + class ResponseConsumer(twisted.internet.protocol.Protocol): def __init__(self, req): self._req = req - self._ssd = SlipStreamDecoder(queue_inbound) + self._ssd = SlipStreamDecoder(crashy) self._log(DBG.HTTP_CTRL, '__init__') def _log(self, dflag, msg, **kwargs): @@ -72,7 +74,7 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): try: self._ssd.inputdata(mime_translate(data)) except Exception as e: - self._asyncfailure(e) + self._handleexception() def connectionMade(self): self._log(DBG.HTTP_CTRL, 'connectionMade') @@ -85,7 +87,10 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): try: self._ssd.flush() except Exception as e: - self._asyncfailure(e) + self._handleexception() + + def _handleexception(self): + self._asyncfailure(traceback.format_exc()) def _asyncfailure(self, reason): self._log(DBG.HTTP_CTRL, '_asyncFailure ' + str(reason)) diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 798f5d2..82f0634 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -23,6 +23,7 @@ from configparser import NoOptionError import collections import time import codecs +import traceback import re as regexp diff --git a/server b/server index e5aa67b..7c66edd 100755 --- a/server +++ b/server @@ -12,8 +12,6 @@ from twisted.web.server import NOT_DONE_YET import syslog -import traceback - clients = { } #---------- "router" ---------- -- 2.30.2 From 7a68893ff08c60d0973b6bebe119c1303d812375 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 22:54:11 +0100 Subject: [PATCH 10/16] wip, fixes --- hippotat/__init__.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 82f0634..4cc9e70 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -163,8 +163,9 @@ class SlipStreamDecoder(): def inputdata(self, data): #print('SLIP-GOT ', repr(data)) - self._buffer += data - packets = slip.decode(self._buffer) + data = self._buffer + data + self._buffer = b'' + packets = slip.decode(data) self._buffer = packets.pop() for packet in packets: self._maybe_packet(packet) -- 2.30.2 From db6ba5840b00c61fe6e576b54179ddeb30202b0e Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:01:04 +0100 Subject: [PATCH 11/16] wip --- client | 4 +--- hippotat/__init__.py | 20 ++++++++++++++------ 2 files changed, 15 insertions(+), 9 deletions(-) diff --git a/client b/client index b5a4db5..e3fcd0d 100755 --- a/client +++ b/client @@ -58,12 +58,10 @@ def outbound(packet, saddr, daddr): queue.append(packet) check_outbound() -def crashy(): assert(False) - class ResponseConsumer(twisted.internet.protocol.Protocol): def __init__(self, req): self._req = req - self._ssd = SlipStreamDecoder(crashy) + self._ssd = SlipStreamDecoder('req %s' % id(req), queue_inbound) self._log(DBG.HTTP_CTRL, '__init__') def _log(self, dflag, msg, **kwargs): diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 4cc9e70..ae13eec 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -39,6 +39,7 @@ class DBG(twisted.python.constants.Names): QUEUE = NamedConstant() QUEUE_CTRL = NamedConstant() HTTP_FULL = NamedConstant() + SLIP_FULL = NamedConstant() _hex_codec = codecs.getencoder('hex_codec') @@ -156,32 +157,39 @@ def ipnetwork(input): #---------- ipif (SLIP) subprocess ---------- class SlipStreamDecoder(): - def __init__(self, on_packet): - # we will call 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 '+msg, **kwargs) def inputdata(self, data): - #print('SLIP-GOT ', repr(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('inputdata bufremain', d=self._buffer) def _maybe_packet(self, packet): - if len(packet): - self._on_packet(packet) + self._log('inputdata maybepacket', d=packet) + if len(packet): + self._on_packet(packet) def flush(self): + self._log('inputdata 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) -- 2.30.2 From 3d003cdd48892205849a0dd17ccbf4c6d3962cbc Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:07:16 +0100 Subject: [PATCH 12/16] wip --- server | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/server b/server index 7c66edd..8a16c34 100755 --- a/server +++ b/server @@ -98,6 +98,10 @@ class Client(): self._rq.append(request) self._check_outbound() + def _req_write(self, req, d): + self._log(DBG.HTTP, 'req_write ', idof=req, d=d) + req.write(d) + def _check_outbound(self): log_debug(DBG.HTTP_CTRL, 'CHKO') while True: @@ -121,7 +125,7 @@ class Client(): self._log(DBG.HTTP_CTRL, 'CHKO processing', idof=request) # request, and also some non-expired packets self._pq.process((lambda: request.sentLength), - request.write, + (lambda d: self._req_write(request, d)), self.max_batch_down) assert(request.sentLength) -- 2.30.2 From 3297cac10f5726598246c6db6cf0efc4c51f355d Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:08:27 +0100 Subject: [PATCH 13/16] wip --- hippotat/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/hippotat/__init__.py b/hippotat/__init__.py index ae13eec..6de4d14 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -164,7 +164,7 @@ class SlipStreamDecoder(): self._log('__init__') def _log(self, msg, **kwargs): - log_debug(DBG.SLIP_FULL, 'slip '+msg, **kwargs) + log_debug(DBG.SLIP_FULL, 'slip %s: %s' % (self._desc, msg), **kwargs) def inputdata(self, data): self._log('inputdata', d=data) -- 2.30.2 From 54890d4de8a936ff4f222fd66541b7318808f7ce Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:11:52 +0100 Subject: [PATCH 14/16] wip --- hippotat/__init__.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 6de4d14..90476f5 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -174,15 +174,15 @@ class SlipStreamDecoder(): self._buffer = packets.pop() for packet in packets: self._maybe_packet(packet) - self._log('inputdata bufremain', d=self._buffer) + self._log('bufremain', d=self._buffer) def _maybe_packet(self, packet): - self._log('inputdata maybepacket', d=packet) + self._log('maybepacket', d=packet) if len(packet): self._on_packet(packet) def flush(self): - self._log('inputdata flush') + self._log('flush') self._maybe_packet(self._buffer) self._buffer = b'' -- 2.30.2 From 02cdcb524f39817d80da3541d3143f698b666ebd Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:14:52 +0100 Subject: [PATCH 15/16] wip IT RETURNED A PACKET --- client | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/client b/client index e3fcd0d..fcdc665 100755 --- a/client +++ b/client @@ -70,7 +70,7 @@ class ResponseConsumer(twisted.internet.protocol.Protocol): def dataReceived(self, data): self._log(DBG.HTTP_CTRL, 'dataReceived', d=data) try: - self._ssd.inputdata(mime_translate(data)) + self._ssd.inputdata(data) except Exception as e: self._handleexception() -- 2.30.2 From ca386ea20592402ba35ced4f7f964f06a6263cab Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Sat, 1 Apr 2017 23:20:54 +0100 Subject: [PATCH 16/16] wip --- hippotat/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/hippotat/__init__.py b/hippotat/__init__.py index 90476f5..c1a6996 100644 --- a/hippotat/__init__.py +++ b/hippotat/__init__.py @@ -50,7 +50,7 @@ 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 = d[0:64] d = _hex_codec(d)[0].decode('ascii') msg += ' ' + d log.info('{dflag} {msgcore}', dflag=dflag, msgcore=msg) -- 2.30.2