Better logging, also for client

hugvey/central_command.py

@@ -509,7 +509,8 @@ class HugveyState(object):
             self.streamer = AudioStreamer(
                 self.command.config['voice']['chunk'],
                 self.ip,
-                int(self.command.config['voice']['port']) + self.id)
+                int(self.command.config['voice']['port']) + self.id,
+                self.id)
     
             if self.command.config['voyeur']:
                 self.logger.warn("Debug on: Connecting Audio player")

hugvey/client.py

@@ -24,6 +24,10 @@ import subprocess
 
 logger = logging.getLogger("client")
 
+def setLogger(hv_id):
+    global logger
+    logger = logging.getLogger("hugvey").getChild("{}".format(hv_id)).getChild("client")
+
 
 class VoiceServer(object):
     """A UDP server, providing mic data at 16 kHz"""
@@ -283,7 +287,8 @@ class Hugvey(object):
 
     def __init__(self, id = None):
         self.id = self.getId() if id is None else id
-        logger.debug('Hugvey {}'.format(self.id))
+        setLogger(self.id)
+        logger.debug('Hugvey {}, reporting'.format(self.id))
 
     def getId(self) -> int:
         """Get Hugvey ID from hostname"""

hugvey/speech/recorder.py

@@ -17,6 +17,8 @@ class Recorder:
     """
 
     def __init__(self, hv_id, src_rate, out_folder):
+        self.logger = mainLogger.getChild(f"{hv_id}").getChild('recorder')
+        
         if not os.path.exists(out_folder):
             raise Exception(f"Invalid output folder for recordings: {out_folder}")
 
@@ -32,11 +34,11 @@ class Recorder:
         self.data = array('h')
         self.currentTranscription = ""
         
-        t = time.strftime("%Y%m%d-%H%M")
+        t = time.strftime("%Y%m%d-%H%M%s")
         
         self.out_folder = os.path.join(self.main_folder, f"{self.hv_id}", t)
         if not os.path.exists(self.out_folder):
-            logger.debug(f"Create directory {self.out_folder}")
+            self.logger.debug(f"Create directory {self.out_folder}")
             self.target_folder = os.makedirs(self.out_folder, exist_ok=True)
         
         self.running = True
@@ -44,11 +46,16 @@ class Recorder:
     
     def writeData(self):
         if len(self.data) < 1:
+            self.logger.info("Skip empty wave creation")
             return
             
         self.fragmentNr += 1
         
-        self.wf = wave.open(os.path.join(self.out_folder, f"{self.fragmentNr}.wav"), 'wb')
+        fn = os.path.join(self.out_folder, f"{self.fragmentNr}.wav")
+        
+        self.logger.info(f"Write wave: {fn}")
+        
+        self.wf = wave.open(fn, 'wb')
         self.wf.setnchannels(1)
         self.wf.setsampwidth(2)
         self.wf.setframerate(self.src_rate)
@@ -67,15 +74,13 @@ class Recorder:
         if not self.running:
             return 
         
-#           logger.debug('receive {}'.format(len(chunk)))
+#           self.logger.debug('receive {}'.format(len(chunk)))
         if audioop.max(chunk, 2) == 0:
             # mic is muted on client side.
             
             self.subsequentMutedFrames += 1
-            logger.warn(f"Empty frame {self.subsequentMutedFrames}")
+            #self.logger.debug(f"Empty frame {self.subsequentMutedFrames}")
-#             self.logger.debug("Muted")
             if self.subsequentMutedFrames == 4:
-                logger.warn("Create new wave!")
 #                 self.createWave()
                 self.writeData()
             if self.subsequentMutedFrames > 4:

hugvey/speech/streamer.py

@@ -10,7 +10,9 @@ mainLogger = logging.getLogger("hugvey")
 logger = mainLogger.getChild("streamer")
 
 class AudioStreamer(object):
-    def __init__(self, chunk, address: str, port: int):
+    def __init__(self, chunk, address: str, port: int, hv_id: int):
+        self.logger = mainLogger.getChild(f"{hv_id}").getChild('streamer')
+        
         self.consumers = []
         
         self.chunk = chunk
@@ -34,18 +36,18 @@ class AudioStreamer(object):
         self.socket.connect(address)
         
 #         s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
-        logger.info("Attempt connection on {}:{}".format(self.address, self.port))
+        self.logger.info("Attempt connection on {}:{}".format(self.address, self.port))
 #         s.connect((self.address, self.port))
 #     
         try:
             while self.isRunning:
                 data = await self.socket.recv()
-    #             logger.debug('chunk received')
+    #             self.logger.debug('chunk received')
                 self.process(data)
         except zmq.error.Again as timeout_e:
-            logger.warn("Timeout of audiostream. Hugvey shutdown?")
+            self.logger.warn("Timeout of audiostream. Hugvey shutdown?")
         finally:
-            logger.info("Close socket on {}:{}".format(self.address, self.port))
+            self.logger.info("Close socket on {}:{}".format(self.address, self.port))
             self.socket.close()
     
     def stop(self):
@@ -56,7 +58,7 @@ class AudioStreamer(object):
     
     
     def process(self, chunk):
-#         logger.debug("Received chunk")
+#         self.logger.debug("Received chunk")
         for consumer in self.consumers:
             consumer.receive(chunk)
         

hugvey_client.py

@@ -1,5 +1,7 @@
 from hugvey.client import Hugvey
-import coloredlogs, logging
+import logging
+import logging.handlers
+import coloredlogs
 import argparse
 
 if __name__ == '__main__':
@@ -28,6 +30,11 @@ if __name__ == '__main__':
     coloredlogs.install(
         level=logging.DEBUG if args.verbose else logging.INFO,
     )
+    
+    logger = logging.getLogger("hugvey")
+#     logger.setLevel(1)  # to send all records to cutelog
+    socket_handler = logging.handlers.SocketHandler('hugveycmd.local', 19996)  # default listening address
+    logger.addHandler(socket_handler);
 
     hv = Hugvey(args.id)
     hv.loadConfig(args.config)