Grasscutters/mitmproxy
3
0
Fork 0
mirror of https://github.com/Grasscutters/mitmproxy.git synced 2024-11-26 18:18:25 +00:00
Code Issues Projects Releases Wiki Activity

Merge pull request #238 from mitmproxy/log_levels

Browse Source 
Log Levels
This commit is contained in:
Maximilian Hils 2014-03-18 17:19:44 +01:00
commit ce38a17893
16 changed files with 105 additions and 99 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

10
libmproxy/cmdline.py
View File

@ -161,7 +161,6 @@ def get_common_options(options):
anticache = options.anticache,
anticomp = options.anticomp,
client_replay = options.client_replay,
eventlog = options.eventlog,
kill = options.kill,
no_server = options.no_server,
refresh_server_playback = not options.norefresh,
@ -196,11 +195,6 @@ def common_options(parser):
action="store", type = str, dest="confdir", default='~/.mitmproxy',
help = "Configuration directory. (~/.mitmproxy)"
)
parser.add_argument(
"-e",
action="store_true", dest="eventlog",
help="Show event log."
)
parser.add_argument(
"-n",
action="store_true", dest="no_server",
@ -281,8 +275,8 @@ def common_options(parser):
)
parser.add_argument(
"-v",
action="count", dest="verbose", default=1,
help="Increase verbosity. Can be passed multiple times."
action="store_const", dest="verbose", default=1, const=2,
help="Increase event log verbosity."
)
parser.add_argument(
"-w",

24
libmproxy/console/__init__.py
View File

@ -437,20 +437,20 @@ class ConsoleMaster(flow.FlowMaster):
status, val = s.run(method, f)
if val:
if status:
self.add_event("Method %s return: %s"%(method, val))
self.add_event("Method %s return: %s"%(method, val), "debug")
else:
self.add_event("Method %s error: %s"%(method, val[1]))
self.add_event("Method %s error: %s"%(method, val[1]), "error")
def run_script_once(self, command, f):
if not command:
return
self.add_event("Running script on flow: %s"%command)
self.add_event("Running script on flow: %s"%command, "debug")
try:
s = script.Script(command, self)
except script.ScriptError, v:
self.statusbar.message("Error loading script.")
self.add_event("Error loading script:\n%s"%v.args[0])
self.add_event("Error loading script:\n%s"%v.args[0], "error")
return
if f.request:
@ -582,7 +582,7 @@ class ConsoleMaster(flow.FlowMaster):
if self.options.rfile:
ret = self.load_flows(self.options.rfile)
if ret and self.state.flow_count():
self.add_event("File truncated or corrupted. Loaded as many flows as possible.")
self.add_event("File truncated or corrupted. Loaded as many flows as possible.","error")
elif not self.state.flow_count():
self.shutdown()
print >> sys.stderr, "Could not load file:", ret
@ -1001,20 +1001,20 @@ class ConsoleMaster(flow.FlowMaster):
self.eventlist[:] = []
def add_event(self, e, level="info"):
if level == "info":
e = urwid.Text(str(e))
elif level == "error":
needed = dict(error=1, info=1, debug=2).get(level, 1)
if self.options.verbosity < needed:
return
if level == "error":
e = urwid.Text(("error", str(e)))
else:
e = urwid.Text(str(e))
self.eventlist.append(e)
if len(self.eventlist) > EVENTLOG_SIZE:
self.eventlist.pop(0)
self.eventlist.set_focus(len(self.eventlist)-1)
# Handlers
def handle_log(self, l):
self.add_event(l.msg)
l.reply()
def handle_error(self, r):
f = flow.FlowMaster.handle_error(self, r)
if f:

2
libmproxy/console/contentview.py
View File

@ -490,7 +490,7 @@ def get_content_view(viewmode, hdrItems, content, limit, logfunc):
except Exception:
s = traceback.format_exc()
s = "Content viewer failed: \n" + s
logfunc(s)
logfunc(s, "error")
ret = None
if not ret:
ret = get("Raw")(hdrs, content, limit)

2
libmproxy/console/flowlist.py
View File

@ -69,7 +69,7 @@ class BodyPile(urwid.Pile):
else:
self.widget_list[1].header = self.inactive_header
key = None
elif key == "v":
elif key == "e":
self.master.toggle_eventlog()
key = None

26
libmproxy/dump.py
View File

@ -15,7 +15,7 @@ class Options(object):
"anticache",
"anticomp",
"client_replay",
"eventlog",
"flow_detail",
"keepserving",
"kill",
"no_server",
@ -66,7 +66,6 @@ class DumpMaster(flow.FlowMaster):
self.o = options
self.anticache = options.anticache
self.anticomp = options.anticomp
self.eventlog = options.eventlog
self.showhost = options.showhost
self.refresh_server_playback = options.refresh_server_playback
@ -127,7 +126,7 @@ class DumpMaster(flow.FlowMaster):
try:
self.load_flows(freader)
except flow.FlowReadError, v:
self.add_event("Flow file corrupted. Stopped loading.")
self.add_event("Flow file corrupted. Stopped loading.", "error")
if self.o.app:
self.start_app(self.o.app_host, self.o.app_port, self.o.app_external)
@ -142,7 +141,8 @@ class DumpMaster(flow.FlowMaster):
return flows
def add_event(self, e, level="info"):
if self.eventlog:
needed = dict(error=1, info=1, debug=2).get(level, 1)
if self.o.verbosity >= needed:
print >> self.outfile, e
self.outfile.flush()
@ -156,12 +156,12 @@ class DumpMaster(flow.FlowMaster):
return
if f.response:
if self.o.flow_detail > 0:
sz = utils.pretty_size(len(f.response.content))
if self.o.verbosity > 0:
result = " << %s %s"%(str_response(f.response), sz)
if self.o.verbosity > 1:
if self.o.flow_detail > 1:
result = result + "\n\n" + self.indent(4, f.response.headers)
if self.o.verbosity > 2:
if self.o.flow_detail > 2:
if utils.isBin(f.response.content):
d = netlib.utils.hexdump(f.response.content)
d = "\n".join("%s\t%s %s"%i for i in d)
@ -174,16 +174,16 @@ class DumpMaster(flow.FlowMaster):
elif f.error:
result = " << %s"%f.error.msg
if self.o.verbosity == 1:
if self.o.flow_detail == 1:
print >> self.outfile, str_request(f.request, self.showhost)
print >> self.outfile, result
elif self.o.verbosity == 2:
elif self.o.flow_detail == 2:
print >> self.outfile, str_request(f.request, self.showhost)
print >> self.outfile, self.indent(4, f.request.headers)
print >> self.outfile
print >> self.outfile, result
print >> self.outfile, "\n"
elif self.o.verbosity >= 3:
elif self.o.flow_detail >= 3:
print >> self.outfile, str_request(f.request, self.showhost)
print >> self.outfile, self.indent(4, f.request.headers)
if utils.isBin(f.request.content):
@ -193,13 +193,9 @@ class DumpMaster(flow.FlowMaster):
print >> self.outfile
print >> self.outfile, result
print >> self.outfile, "\n"
if self.o.verbosity:
if self.o.flow_detail:
self.outfile.flush()
def handle_log(self, l):
self.add_event(l.msg)
l.reply()
def handle_request(self, r):
f = flow.FlowMaster.handle_request(self, r)
if f:

6
libmproxy/flow.py
View File

@ -480,7 +480,7 @@ class FlowMaster(controller.Master):
def add_event(self, e, level="info"):
"""
level: info, error
level: debug, info, error
"""
pass
@ -659,6 +659,10 @@ class FlowMaster(controller.Master):
if block:
rt.join()
def handle_log(self, l):
self.add_event(l.msg, l.level)
l.reply()
def handle_clientconnect(self, cc):
self.run_script_hook("clientconnect", cc)
cc.reply()

28
libmproxy/protocol/http.py
View File

@ -861,7 +861,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
return HTTPResponse.from_stream(self.c.server_conn.rfile, request.method,
body_size_limit=self.c.config.body_size_limit)
except (tcp.NetLibDisconnect, http.HttpErrorConnClosed), v:
self.c.log("error in server communication: %s" % str(v))
self.c.log("error in server communication: %s" % str(v), level="debug")
if i < 1:
# In any case, we try to reconnect at least once.
# This is necessary because it might be possible that we already initiated an upstream connection
@ -881,7 +881,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
try:
req = HTTPRequest.from_stream(self.c.client_conn.rfile,
body_size_limit=self.c.config.body_size_limit)
self.c.log("request", [req._assemble_first_line(req.form_in)])
self.c.log("request", "debug", [req._assemble_first_line(req.form_in)])
send_upstream = self.process_request(flow, req)
if not send_upstream:
return True
@ -906,7 +906,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
flow.server_conn = self.c.server_conn # no further manipulation of self.c.server_conn beyond this point
# we can safely set it as the final attribute value here.
self.c.log("response", [flow.response._assemble_first_line()])
self.c.log("response", "debug", [flow.response._assemble_first_line()])
response_reply = self.c.channel.ask("response", flow.response)
if response_reply is None or response_reply == KILL:
return False
@ -946,7 +946,7 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
else:
err = error.__class__
self.c.log("error: %s" % err)
self.c.log("error: %s" % err, level="info")
if flow:
flow.error = Error(err)
@ -985,21 +985,23 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
Hooking code isn't particulary beautiful, but it isolates this edge-case from
the protocol-agnostic ConnectionHandler
"""
self.c.log("Hook reconnect function")
self.c.log("Hook reconnect function", level="debug")
original_reconnect_func = self.c.server_reconnect
def reconnect_http_proxy():
self.c.log("Hooked reconnect function")
self.c.log("Hook: Run original reconnect")
self.c.log("Hooked reconnect function", "debug")
self.c.log("Hook: Run original reconnect", "debug")
original_reconnect_func(no_ssl=True)
self.c.log("Hook: Write CONNECT request to upstream proxy", [upstream_request._assemble_first_line()])
self.c.log("Hook: Write CONNECT request to upstream proxy", "debug",
[upstream_request._assemble_first_line()])
self.c.server_conn.send(upstream_request._assemble())
self.c.log("Hook: Read answer to CONNECT request from proxy")
self.c.log("Hook: Read answer to CONNECT request from proxy", "debug")
resp = HTTPResponse.from_stream(self.c.server_conn.rfile, upstream_request.method)
if resp.code != 200:
raise proxy.ProxyError(resp.code,
"Cannot reestablish SSL connection with upstream proxy: \r\n" + str(resp.headers))
self.c.log("Hook: Establish SSL with upstream proxy")
"Cannot reestablish SSL "
"connection with upstream proxy: \r\n" + str(resp.headers))
self.c.log("Hook: Establish SSL with upstream proxy", "debug")
self.c.establish_ssl(server=True)
self.c.server_reconnect = reconnect_http_proxy
@ -1008,11 +1010,11 @@ class HTTPHandler(ProtocolHandler, TemporaryServerChangeMixin):
"""
Upgrade the connection to SSL after an authority (CONNECT) request has been made.
"""
self.c.log("Received CONNECT request. Upgrading to SSL...")
self.c.log("Received CONNECT request. Upgrading to SSL...", "debug")
self.expected_form_in = "relative"
self.expected_form_out = "relative"
self.c.establish_ssl(server=True, client=True)
self.c.log("Upgrade to SSL completed.")
self.c.log("Upgrade to SSL completed.", "debug")
def process_request(self, flow, request):

4
libmproxy/protocol/primitives.py
View File

@ -172,7 +172,7 @@ class TemporaryServerChangeMixin(object):
self.c.server_conn.address.port,
address.host,
address.port
))
), "debug")
if not hasattr(self, "_backup_server_conn"):
self._backup_server_conn = self.c.server_conn
@ -193,7 +193,7 @@ class TemporaryServerChangeMixin(object):
self.c.server_conn.address.port,
self._backup_server_conn.address.host,
self._backup_server_conn.address.port
))
), "debug")
self.c.del_server_connection()
self.c.server_conn = self._backup_server_conn

4
libmproxy/protocol/tcp.py
View File

@ -45,7 +45,7 @@ class TCPHandler(ProtocolHandler):
data = data.getvalue()
if data == "": # no data received, rfile is closed
self.c.log("Close writing connection to %s" % dst_str)
self.c.log("Close writing connection to %s" % dst_str, "debug")
conns.remove(rfile)
if dst.ssl_established:
dst.connection.shutdown()
@ -55,6 +55,6 @@ class TCPHandler(ProtocolHandler):
self.c.close = True
break
self.c.log("%s %s\r\n%s" % (direction, dst_str,data))
self.c.log("%s %s\r\n%s" % (direction, dst_str, data), "debug")
dst.wfile.write(data)
dst.wfile.flush()

3
libmproxy/proxy/primitives.py
View File

@ -67,5 +67,6 @@ class AddressPriority(object):
class Log:
def __init__(self, msg):
def __init__(self, msg, level="info"):
self.msg = msg
self.level = level

33
libmproxy/proxy/server.py
View File

@ -66,7 +66,7 @@ class ConnectionHandler:
self.sni = None
def handle(self):
self.log("clientconnect")
self.log("clientconnect", "info")
self.channel.ask("clientconnect", self)
self.determine_conntype()
@ -86,7 +86,7 @@ class ConnectionHandler:
try:
handle_messages(self.conntype, self)
except ConnectionTypeChange:
self.log("Connection Type Changed: %s" % self.conntype)
self.log("Connection Type Changed: %s" % self.conntype, "info")
continue
# FIXME: Do we want to persist errors?
@ -94,14 +94,14 @@ class ConnectionHandler:
handle_error(self.conntype, self, e)
except Exception, e:
import traceback, sys
self.log(traceback.format_exc())
self.log(traceback.format_exc(), "error")
print >> sys.stderr, traceback.format_exc()
print >> sys.stderr, "mitmproxy has crashed!"
print >> sys.stderr, "Please lodge a bug report at: https://github.com/mitmproxy/mitmproxy"
raise e
self.del_server_connection()
self.log("clientdisconnect")
self.log("clientdisconnect", "info")
self.channel.tell("clientdisconnect", self)
def del_server_connection(self):
@ -110,7 +110,8 @@ class ConnectionHandler:
"""
if self.server_conn and self.server_conn.connection:
self.server_conn.finish()
self.log("serverdisconnect", ["%s:%s" % (self.server_conn.address.host, self.server_conn.address.port)])
self.log("serverdisconnect", "debug", ["%s:%s" % (self.server_conn.address.host,
self.server_conn.address.port)])
self.channel.tell("serverdisconnect", self)
self.server_conn = None
self.sni = None
@ -129,7 +130,7 @@ class ConnectionHandler:
if self.server_conn:
if self.server_conn.priority > priority:
self.log("Attempt to change server address, "
"but priority is too low (is: %s, got: %s)" % (self.server_conn.priority, priority))
"but priority is too low (is: %s, got: %s)" % (self.server_conn.priority, priority), "info")
return
if self.server_conn.address == address:
self.server_conn.priority = priority # Possibly increase priority
@ -137,7 +138,7 @@ class ConnectionHandler:
self.del_server_connection()
self.log("Set new server address: %s:%s" % (address.host, address.port))
self.log("Set new server address: %s:%s" % (address.host, address.port), "debug")
self.server_conn = ServerConnection(address, priority)
def establish_server_connection(self):
@ -147,7 +148,7 @@ class ConnectionHandler:
"""
if self.server_conn.connection:
return
self.log("serverconnect", ["%s:%s" % self.server_conn.address()[:2]])
self.log("serverconnect", "debug", ["%s:%s" % self.server_conn.address()[:2]])
self.channel.tell("serverconnect", self)
try:
self.server_conn.connect()
@ -176,7 +177,7 @@ class ConnectionHandler:
subs.append("with client")
if server:
subs.append("with server (sni: %s)" % self.sni)
self.log("Establish SSL", subs)
self.log("Establish SSL", "debug", subs)
if server:
if self.server_conn.ssl_established:
@ -199,7 +200,7 @@ class ConnectionHandler:
had_ssl = self.server_conn.ssl_established
priority = self.server_conn.priority
sni = self.sni
self.log("(server reconnect follows)")
self.log("(server reconnect follows)", "debug")
self.del_server_connection()
self.set_server_address(address, priority)
self.establish_server_connection()
@ -210,14 +211,14 @@ class ConnectionHandler:
def finish(self):
self.client_conn.finish()
def log(self, msg, subs=()):
def log(self, msg, level, subs=()):
msg = [
"%s:%s: %s" % (self.client_conn.address.host, self.client_conn.address.port, msg)
]
for i in subs:
msg.append(" -> " + i)
msg = "\n".join(msg)
self.channel.tell("log", Log(msg))
self.channel.tell("log", Log(msg, level))
def find_cert(self):
if self.config.certforward and self.server_conn.ssl_established:
@ -246,15 +247,17 @@ class ConnectionHandler:
sn = connection.get_servername()
if sn and sn != self.sni:
self.sni = sn.decode("utf8").encode("idna")
self.log("SNI received: %s" % self.sni)
self.log("SNI received: %s" % self.sni, "debug")
self.server_reconnect() # reconnect to upstream server with SNI
# Now, change client context to reflect changed certificate:
new_context = SSL.Context(SSL.TLSv1_METHOD)
cert, key = self.find_cert()
new_context.use_privatekey_file(key)
new_context.use_certificate(cert.X509)
new_context.use_privatekey(key)
new_context.use_certificate(cert.x509)
connection.set_context(new_context)
# An unhandled exception in this method will core dump PyOpenSSL, so
# make dang sure it doesn't happen.
except Exception, e: # pragma: no cover
import traceback
self.log("Error in handle_sni:\r\n" + traceback.format_exc(), "error")
pass

10
libmproxy/script.py
View File

@ -10,15 +10,15 @@ class ScriptContext:
def __init__(self, master):
self._master = master
def log(self, *args, **kwargs):
def log(self, message, level="info"):
"""
Logs an event.
How this is handled depends on the front-end. mitmdump will display
events if the eventlog flag ("-e") was passed. mitmproxy sends
output to the eventlog for display ("v" keyboard shortcut).
By default, only events with level "error" get displayed. This can be controlled with the "-v" switch.
How log messages are handled depends on the front-end. mitmdump will print them to stdout,
mitmproxy sends output to the eventlog for display ("e" keyboard shortcut).
"""
self._master.add_event(*args, **kwargs)
self._master.add_event(message, level)
def duplicate_flow(self, f):
"""

11
mitmdump
View File

@ -21,12 +21,18 @@ if __name__ == '__main__':
action="store_true", dest="keepserving", default=False,
help="Continue serving after client playback or file read. We exit by default."
)
parser.add_argument(
"-d",
action="count", dest="flow_detail", default=1,
help="Increase flow detail display level. Can be passed multiple times."
)
parser.add_argument('args', nargs=argparse.REMAINDER)
options = parser.parse_args()
if options.quiet:
options.verbose = 0
options.flow_detail = 0
proxyconfig = process_proxy_options(parser, options)
if options.no_server:
@ -38,11 +44,8 @@ if __name__ == '__main__':
print >> sys.stderr, "mitmdump:", v.args[0]
sys.exit(1)
try:
dumpopts = dump.Options(**cmdline.get_common_options(options))
except cmdline.OptionException, v:
parser.error(v.message)
dumpopts.flow_detail = options.flow_detail
dumpopts.keepserving = options.keepserving
if options.args:

9
mitmproxy
View File

@ -23,6 +23,11 @@ if __name__ == '__main__':
action="store", dest="palette",
help="Select color palette: " + ", ".join(palettes.palettes.keys())
)
parser.add_argument(
"-e",
action="store_true", dest="eventlog",
help="Show event log."
)
group = parser.add_argument_group(
@ -47,10 +52,8 @@ if __name__ == '__main__':
print >> sys.stderr, "mitmproxy:", v.args[0]
sys.exit(1)
try:
opts = console.Options(**cmdline.get_common_options(options))
except cmdline.OptionException, v:
parser.error(v.message)
opts.eventlog = options.eventlog
opts.intercept = options.intercept
opts.debug = options.debug
opts.palette = options.palette

12
test/test_console_contentview.py
View File

@ -190,7 +190,7 @@ Larry
[["content-type", "application/json"]],
"[1, 2, 3]",
1000,
lambda x: None
lambda x, l: None
)
assert "Raw" in r[0]
@ -199,7 +199,7 @@ Larry
[["content-type", "application/json"]],
"[1, 2, 3]",
1000,
lambda x: None
lambda x, l: None
)
assert r[0] == "JSON"
@ -208,7 +208,7 @@ Larry
[["content-type", "application/json"]],
"[1, 2",
1000,
lambda x: None
lambda x, l: None
)
assert "Raw" in r[0]
@ -217,7 +217,7 @@ Larry
[],
"[1, 2",
1000,
lambda x: None
lambda x, l: None
)
assert "Raw" in r[0]
@ -230,7 +230,7 @@ Larry
],
encoding.encode('gzip', "[1, 2, 3]"),
1000,
lambda x: None
lambda x, l: None
)
assert "decoded gzip" in r[0]
assert "JSON" in r[0]
@ -243,7 +243,7 @@ Larry
],
encoding.encode('gzip', "[1, 2, 3]"),
1000,
lambda x: None
lambda x, l: None
)
assert "decoded gzip" in r[0]
assert "Raw" in r[0]

12
test/test_dump.py
View File

@ -56,7 +56,7 @@ class TestDumpMaster:
def test_error(self):
cs = StringIO()
o = dump.Options(verbosity=1)
o = dump.Options(flow_detail=1)
m = dump.DumpMaster(None, o, None, outfile=cs)
f = tutils.tflow_err()
m.handle_request(f.request)
@ -90,7 +90,7 @@ class TestDumpMaster:
with tutils.tmpdir() as t:
p = os.path.join(t, "read")
self._flowfile(p)
assert "GET" in self._dummy_cycle(0, None, "", verbosity=1, rfile=p)
assert "GET" in self._dummy_cycle(0, None, "", flow_detail=1, rfile=p)
tutils.raises(
dump.DumpError, self._dummy_cycle,
@ -127,9 +127,9 @@ class TestDumpMaster:
def test_basic(self):
for i in (1, 2, 3):
assert "GET" in self._dummy_cycle(1, "~s", "", verbosity=i, eventlog=True)
assert "GET" in self._dummy_cycle(1, "~s", "\x00\x00\x00", verbosity=i)
assert "GET" in self._dummy_cycle(1, "~s", "ascii", verbosity=i)
assert "GET" in self._dummy_cycle(1, "~s", "", flow_detail=i)
assert "GET" in self._dummy_cycle(1, "~s", "\x00\x00\x00", flow_detail=i)
assert "GET" in self._dummy_cycle(1, "~s", "ascii", flow_detail=i)
def test_write(self):
with tutils.tmpdir() as d:
@ -150,7 +150,7 @@ class TestDumpMaster:
def test_script(self):
ret = self._dummy_cycle(
1, None, "",
scripts=[tutils.test_data.path("scripts/all.py")], verbosity=0, eventlog=True
scripts=[tutils.test_data.path("scripts/all.py")], verbosity=1
)
assert "XCLIENTCONNECT" in ret
assert "XSERVERCONNECT" in ret