From f83daa5a22a92fd0fd46bd347e5b95d7f14e3876 Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Thu, 11 Aug 2016 04:44:09 +0000 Subject: [PATCH] more logging on the server side --- lbrynet/__init__.py | 6 ----- lbrynet/core/log_support.py | 4 +++- lbrynet/lbrynet_daemon/LBRYDaemon.py | 4 ++-- lbrynet/lbrynet_daemon/LBRYDaemonControl.py | 4 ++-- lbrynet/reflector/server/server.py | 25 +++++++++++++++------ 5 files changed, 25 insertions(+), 18 deletions(-) diff --git a/lbrynet/__init__.py b/lbrynet/__init__.py index 6b754d3a2..9a7032852 100644 --- a/lbrynet/__init__.py +++ b/lbrynet/__init__.py @@ -1,8 +1,2 @@ -import logging - -log = logging.getLogger(__name__) -logging.getLogger(__name__).addHandler(logging.NullHandler()) -log.setLevel(logging.INFO) - __version__ = "0.3.17" version = tuple(__version__.split('.')) \ No newline at end of file diff --git a/lbrynet/core/log_support.py b/lbrynet/core/log_support.py index 50fb35e83..9644888df 100644 --- a/lbrynet/core/log_support.py +++ b/lbrynet/core/log_support.py @@ -58,8 +58,10 @@ def _log_decorator(fn): handler = fn(*args, **kwargs) if handler.name: remove_handlers(log, handler.name) + handler.setLevel(level) log.addHandler(handler) - log.setLevel(level) + if log.level > level: + log.setLevel(level) return helper diff --git a/lbrynet/lbrynet_daemon/LBRYDaemon.py b/lbrynet/lbrynet_daemon/LBRYDaemon.py index 026793d43..f9c0a7cbe 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemon.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemon.py @@ -213,7 +213,7 @@ class LBRYDaemon(jsonrpc.JSONRPC): 'use_upnp': True, 'start_lbrycrdd': True, 'requested_first_run_credits': False, - 'run_reflector_server': False, + 'run_reflector_server': True, 'cache_time': DEFAULT_CACHE_TIME, 'startup_scripts': [], 'last_version': {'lbrynet': lbrynet_version, 'lbryum': lbryum_version} @@ -683,8 +683,8 @@ class LBRYDaemon(jsonrpc.JSONRPC): def _start_reflector(self): if self.run_reflector_server: - log.info("Starting reflector server") if self.reflector_port is not None: + log.info("Starting reflector server listening to %s", self.reflector_port) reflector_factory = reflector.ServerFactory( self.session.peer_manager, self.session.blob_manager diff --git a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py index 76cbe5152..4d68424c0 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py @@ -74,8 +74,8 @@ def start(): args = parser.parse_args() log_support.disable_noisy_loggers() - log_support.configure_file_handler(lbrynet_log) - log_support.configure_loggly_handler() + log_support.configure_file_handler(lbrynet_log, level=10) + log_support.configure_loggly_handler(level=10) if args.logtoconsole: log_support.configure_console(level='DEBUG') diff --git a/lbrynet/reflector/server/server.py b/lbrynet/reflector/server/server.py index d2569b6aa..b8a1c6d68 100644 --- a/lbrynet/reflector/server/server.py +++ b/lbrynet/reflector/server/server.py @@ -11,9 +11,9 @@ log = logging.getLogger(__name__) class ReflectorServer(Protocol): - def connectionMade(self): peer_info = self.transport.getPeer() + log.debug('Connection made to %s', peer_info) self.peer = self.factory.peer_manager.get_peer(peer_info.host, peer_info.port) self.blob_manager = self.factory.blob_manager self.received_handshake = False @@ -29,17 +29,21 @@ class ReflectorServer(Protocol): pass def dataReceived(self, data): - if self.receiving_blob is False: + log.debug('Recieved data: %s', data) + if self.receiving_blob: + log.debug('Writing data to blob') + self.blob_write(data) + else: + log.debug('Not yet recieving blob, data needs further processing') self.request_buff += data msg, extra_data = self._get_valid_response(self.request_buff) - if msg is not None: + if msg: self.request_buff = '' d = self.handle_request(msg) d.addCallbacks(self.send_response, self.handle_error) - if self.receiving_blob is True and len(extra_data) != 0: + if self.receiving_blob and extra_data: + log.debug('Writing extra data to blog') self.blob_write(extra_data) - else: - self.blob_write(data) def _get_valid_response(self, response_msg): extra_data = None @@ -70,6 +74,7 @@ class ReflectorServer(Protocol): return self.handle_normal_request(request_dict) def handle_handshake(self, request_dict): + log.debug('Handling handshake') if 'version' not in request_dict: raise ValueError("Client should send version") self.peer_version = int(request_dict['version']) @@ -103,6 +108,7 @@ class ReflectorServer(Protocol): raise ValueError("Expected a blob hash and a blob size") if not is_valid_blobhash(request_dict['blob_hash']): raise ValueError("Got a bad blob hash: {}".format(request_dict['blob_hash'])) + log.debug('Recieved info for blob: %s', request_dict['blob_hash']) d = self.blob_manager.get_blob( request_dict['blob_hash'], True, @@ -114,6 +120,7 @@ class ReflectorServer(Protocol): # important in it. to the deferred that fires when the blob is done, # add a callback which returns a nice response dict saying to keep # sending, and then return that deferred + log.debug('blob is already open') self.receiving_blob = True d = self.blob_finished_d d.addCallback(lambda _: self.close_blob()) @@ -133,4 +140,8 @@ class ReflectorServerFactory(ServerFactory): def __init__(self, peer_manager, blob_manager): self.peer_manager = peer_manager - self.blob_manager = blob_manager \ No newline at end of file + self.blob_manager = blob_manager + + def buildProtocol(self, addr): + log.debug('Creating a protocol for %s', addr) + ServerFactory.buildProtocol(self, addr)