Improve logging

lib/jsonrpc.py

@@ -191,12 +191,12 @@ class JSONRPC(asyncio.Protocol, LoggedClass):
 
     def pause_writing(self):
         '''Called by asyncio when the write buffer is full.'''
-        self.log_info('pausing writing')
+        self.log_info('pausing request processing whilst socket drains')
         self.pause = True
 
     def resume_writing(self):
         '''Called by asyncio when the write buffer has room.'''
-        self.log_info('resuming writing')
+        self.log_info('resuming request processing')
         self.pause = False
 
     def close_connection(self):

server/block_processor.py

@@ -199,7 +199,11 @@ class BlockProcessor(server.db.DB):
                 break
             blocks = self.prefetcher.get_blocks()
             if blocks:
+                start = time.time()
                 await self.advance_blocks(blocks, touched)
+                s = '' if len(blocks) == 1 else 's'
+                self.logger.info('processed {:,d} block{} in {:.1f}s'
+                                 .format(len(blocks), s, time.time() - start))
             elif not self.caught_up:
                 self.caught_up = True
                 self.first_caught_up()

server/protocol.py

@@ -161,7 +161,8 @@ class ServerManager(util.LoggedClass):
         excess = priority - self.BANDS
         if excess > 0:
             secs = excess
-            session.log_info('delaying response {:d}s'.format(secs))
+            session.log_info('delaying response to low-priority session {:d}s'
+                             .format(secs))
         if secs:
             self.delayed_sessions.append((time.time() + secs, item))
         else:
@@ -334,8 +335,9 @@ class ServerManager(util.LoggedClass):
         group = self.groups[int(session.start - self.start) // 900]
         group.add(session)
         self.sessions[session] = group
-        session.log_info('connection from {}, {:,d} total'
-                         .format(session.peername(), len(self.sessions)))
+        session.log_info('{} from {}, {:,d} total'
+                         .format(session.kind, session.peername(),
+                                 len(self.sessions)))
         if (len(self.sessions) >= self.max_sessions
                and self.state == self.LISTENING):
             self.state = self.PAUSED