From f3cbbf5b914bd8e60f6d1927859821572658a458 Mon Sep 17 00:00:00 2001
From: Philipp Spitzer <philipp@spitzer.priv.at>
Date: Thu, 9 Jul 2020 22:32:30 +0200
Subject: [PATCH] Improve logging.

---
 lagarde.py | 39 +++++++++++++++++++--------------------
 1 file changed, 19 insertions(+), 20 deletions(-)

diff --git a/lagarde.py b/lagarde.py
index 75a81a7..eca29c9 100755
--- a/lagarde.py
+++ b/lagarde.py
@@ -35,14 +35,14 @@ class Lagarde:
         self.webrtcbin = None
 
     def on_negotiation_needed(self, element):
-        log.info('on_negotiation_needed')
+        log.debug('on_negotiation_needed')
 
     def on_ice_candidate(self, element, mlineindex, candidate):
-        log.info('on_ice_candidate')
+        log.debug('on_ice_candidate')
         self.generated_ice_candidates.append((mlineindex, candidate))
 
     def webrtcbin_pad_added(self, element, pad):
-        log.info('webrtcbin_pad_added')
+        log.debug('webrtcbin_pad_added')
         if pad.direction != Gst.PadDirection.SRC:
             return
         decodebin = Gst.ElementFactory.make('decodebin')
@@ -52,9 +52,9 @@ class Lagarde:
         self.webrtcbin.link(decodebin)
 
     def decodebin_pad_added(self, element, pad):
-        log.info('decodebin_pad_added')
+        log.debug('decodebin_pad_added')
         if not pad.has_current_caps():
-            log.info(pad, 'has no caps, ignoring')
+            log.debug(pad, 'has no caps, ignoring')
             return
 
         caps = pad.get_current_caps()
@@ -121,7 +121,6 @@ class Lagarde:
                     await asyncio.get_event_loop().run_in_executor(None, gst_promise.wait)
                     self.sdp_offer = None
 
-                    log.info('create-answer')
                     gst_promise = Gst.Promise.new()
                     self.webrtcbin.emit('create-answer', None, gst_promise)
                     result = await asyncio.get_event_loop().run_in_executor(None, gst_promise.wait)
@@ -134,7 +133,7 @@ class Lagarde:
                     self.mids = [sdp_message.get_media(i).get_attribute_val('mid')
                                           for i in range(sdp_message.medias_len())]
                     sdp_answer = sdp_message.as_text()
-                    log.info(sdp_answer)
+                    log.info(f'Send SDP answer:\n{sdp_answer}')
                     sdp_answer_msg = json.dumps({
                         'SessionID': self.session_id,
                         'Type': "gotAnswer",
@@ -156,17 +155,18 @@ class Lagarde:
 
                 elif len(self.generated_ice_candidates) > 0:
                     mlineindex, candidate = self.generated_ice_candidates.pop(0)
+                    icemsg_value = json.dumps({
+                        "candidate": candidate,
+                        "sdpMid": self.mids[mlineindex],
+                        "sdpMLineIndex": mlineindex,
+                        "usernameFragment": self.user_fragments[mlineindex],
+                    })
                     icemsg = json.dumps({
                         'SessionID': self.session_id,
                         'Type': 'addCalleeIceCandidate',
-                        'Value': json.dumps({
-                            "candidate": candidate,
-                            "sdpMid": self.mids[mlineindex],
-                            "sdpMLineIndex": mlineindex,
-                            "usernameFragment": self.user_fragments[mlineindex],
-                        })
+                        'Value': icemsg_value,
                     })
-                    log.info(f'send_ice_candidate_message with {icemsg}')
+                    log.info(f'Send ICE candidate: {icemsg_value}')
                     await self.websocket.send(icemsg)
 
                 else:
@@ -183,22 +183,21 @@ class Lagarde:
                 msg_json = json.loads(msg)
                 msg_type = msg_json['Type']
                 msg_value = msg_json['Value']
-                log.info(f"receive for session {self.session_id} type {msg_type}")
+                assert self.session_id is None or self.session_id == msg_json['SessionID']
                 if msg_type == 'newSession':
                     self.session_id = msg_json['SessionID']
+                    log.info(f"New session {self.session_id}")
                 elif msg_type == 'gotOffer':
-                    assert self.session_id == msg_json['SessionID']
                     value_json = json.loads(msg_value)
                     sdp = value_json['sdp']
-                    log.info(f'SDP: {sdp}')
+                    log.info(f'Got SDP offer:\n{sdp}')
                     self.sdp_offer = sdp
                 elif msg_type == 'addCallerIceCandidate':
-                    assert self.session_id == msg_json['SessionID']
                     value_json = json.loads(msg_value)
-                    log.info(f'ICE: {value_json}')
+                    log.info(f'Got ICE candidate: {value_json}')
                     self.received_ice_candidates.append(value_json)
                 elif msg_type == 'roomClosed':
-                    log.info('Oh noes, the room went away!')
+                    log.info(f'Oh noes, the room went away (session {self.session_id})!')
                     self.session_id = None
                     return
                 else:
-- 
2.39.5