more logging on the server side

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('.'))

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
 
 

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

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')
 

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())
@@ -134,3 +141,7 @@ class ReflectorServerFactory(ServerFactory):
     def __init__(self, peer_manager, blob_manager):
         self.peer_manager = peer_manager
         self.blob_manager = blob_manager
+
+    def buildProtocol(self, addr):
+        log.debug('Creating a protocol for %s', addr)
+        ServerFactory.buildProtocol(self, addr)