fix(logger): Logging enhancements.

Get rid of noisy logs related to SDP transformations which are redundant. Fix formatting and add missing information.

modules/RTC/TraceablePeerConnection.js

@@ -901,7 +901,7 @@ TraceablePeerConnection.prototype._remoteTrackAdded = function(stream, track, tr
         return;
     }
 
-    logger.log(`${this} associated ssrc`, ownerEndpointId, trackSsrc);
+    logger.log(`${this} associated ssrc:${trackSsrc} to endpoint:${ownerEndpointId}`);
 
     const peerMediaInfo
         = this.signalingLayer.getPeerMediaInfo(ownerEndpointId, mediaType);
@@ -2901,23 +2901,11 @@ TraceablePeerConnection.prototype._processLocalSSRCsMap = function(ssrcMap) {
 
             // eslint-disable-next-line no-negated-condition
             if (newSSRCNum !== oldSSRCNum) {
-                if (oldSSRCNum === null) {
-                    logger.info(
-                        `Storing new local SSRC for ${track} in ${this}`,
-                        newSSRC);
-                } else {
-                    logger.error(
-                        `Overwriting SSRC for ${track} ${trackMSID} in ${this
-                        } with: `, newSSRC);
+                if (!oldSSRCNum) {
+                    logger.error(`Overwriting SSRC for ${track} ${trackMSID} in ${this} with: `, newSSRC);
                 }
                 this.localSSRCs.set(track.rtcId, newSSRC);
-
-                this.eventEmitter.emit(
-                    RTCEvents.LOCAL_TRACK_SSRC_UPDATED, track, newSSRCNum);
-            } else {
-                logger.debug(
-                    `The local SSRC(${newSSRCNum}) for ${track} ${trackMSID}`
-                     + `is still up to date in ${this}`);
+                this.eventEmitter.emit(RTCEvents.LOCAL_TRACK_SSRC_UPDATED, track, newSSRCNum);
             }
         } else if (!track.isVideoTrack() && !track.isMuted()) {
             // It is normal to find no SSRCs for a muted video track in
@@ -3033,5 +3021,5 @@ TraceablePeerConnection.prototype.generateNewStreamSSRCInfo = function(track) {
  * @return {string}
  */
 TraceablePeerConnection.prototype.toString = function() {
-    return `TPC[${this.id},p2p:${this.isP2P}]`;
+    return `TPC[${this.id},${this.isP2P ? 'P2P' : 'JVB'}]`;
 };

modules/connectivity/ParticipantConnectionStatus.js

@@ -612,7 +612,6 @@ export default class ParticipantConnectionStatusHandler {
         if (typeof isConnActiveByJvb !== 'boolean') {
             // If no status was received from the JVB it means that it's active
             // (the bridge does not send notification unless there is a problem)
-            logger.debug('Assuming connection active by JVB - no notification');
             isConnActiveByJvb = true;
         }
 

modules/e2ee/E2EEncryption.js

@@ -205,9 +205,7 @@ export class E2EEncryption {
      * Advances (using ratcheting) the current key when a new participant joins the conference.
      * @private
      */
-    _onParticipantJoined(id) {
-        logger.debug(`Participant ${id} joined`);
-
+    _onParticipantJoined() {
         if (this._conferenceJoined && this._enabled) {
             this._ratchetKey();
         }
@@ -218,8 +216,6 @@ export class E2EEncryption {
      * @private
      */
     _onParticipantLeft(id) {
-        logger.debug(`Participant ${id} left`);
-
         this._e2eeCtx.cleanup(id);
 
         if (this._enabled) {

modules/sdp/LocalSdpMunger.js

@@ -77,12 +77,6 @@ export default class LocalSdpMunger {
                 = mediaStream && this.tpc.isMediaStreamInPc(mediaStream);
             const shouldFakeSdp = muted || !isInPeerConnection;
 
-            logger.debug(
-                `${this.tpc} ${videoTrack} muted: ${
-                    muted}, is in PeerConnection: ${
-                    isInPeerConnection} => should fake sdp ? : ${
-                    shouldFakeSdp}`);
-
             if (!shouldFakeSdp) {
                 continue; // eslint-disable-line no-continue
             }
@@ -94,8 +88,7 @@ export default class LocalSdpMunger {
                     : [ this.tpc.sdpConsistency.cachedPrimarySsrc ];
 
             if (!requiredSSRCs.length) {
-                logger.error(
-                    `No SSRCs stored for: ${videoTrack} in ${this.tpc}`);
+                logger.error(`No SSRCs stored for: ${videoTrack} in ${this.tpc}`);
 
                 continue; // eslint-disable-line no-continue
             }
@@ -122,9 +115,6 @@ export default class LocalSdpMunger {
                 videoMLine.removeSSRC(ssrcNum);
 
                 // Inject
-                logger.debug(
-                    `${this.tpc} injecting video SSRC: ${ssrcNum} for ${
-                        videoTrack}`);
                 videoMLine.addSSRCAttribute({
                     id: ssrcNum,
                     attribute: 'cname',
@@ -144,9 +134,6 @@ export default class LocalSdpMunger {
 
                 if (!videoMLine.findGroup(group.semantics, group.ssrcs)) {
                     // Inject the group
-                    logger.debug(
-                        `${this.tpc} injecting SIM group for ${videoTrack}`,
-                        group);
                     videoMLine.addSSRCGroup(group);
                 }
             }

modules/sdp/RtxModifier.js

@@ -21,9 +21,6 @@ const logger = getLogger(__filename);
  * @param {number} rtxSsrc the rtx ssrc to associate with the primary ssrc
  */
 function updateAssociatedRtxStream(mLine, primarySsrcInfo, rtxSsrc) {
-    logger.debug(
-        `Updating mline to associate ${rtxSsrc} `
-        + `rtx ssrc with primary stream, ${primarySsrcInfo.id}`);
     const primarySsrc = primarySsrcInfo.id;
     const primarySsrcMsid = primarySsrcInfo.msid;
     const primarySsrcCname = primarySsrcInfo.cname;
@@ -31,22 +28,12 @@ function updateAssociatedRtxStream(mLine, primarySsrcInfo, rtxSsrc) {
     const previousRtxSSRC = mLine.getRtxSSRC(primarySsrc);
 
     if (previousRtxSSRC === rtxSsrc) {
-        logger.debug(`${rtxSsrc} was already associated with ${primarySsrc}`);
-
         return;
     }
     if (previousRtxSSRC) {
-        logger.debug(
-            `${primarySsrc} was previously associated with rtx `
-            + `${previousRtxSSRC}, removing all references to it`);
-
         // Stream already had an rtx ssrc that is different than the one given,
         //  remove all trace of the old one
         mLine.removeSSRC(previousRtxSSRC);
-
-        logger.debug(`groups before filtering for ${previousRtxSSRC}`);
-        logger.debug(mLine.dumpSSRCGroups());
-
         mLine.removeGroupsWithSSRC(previousRtxSSRC);
     }
     mLine.addSSRCAttribute({
@@ -135,50 +122,30 @@ export default class RtxModifier {
      */
     modifyRtxSsrcs2(videoMLine) {
         if (videoMLine.direction === 'recvonly') {
-            logger.debug('RtxModifier doing nothing, video m line is recvonly');
 
             return false;
         }
         if (videoMLine.getSSRCCount() < 1) {
-            logger.debug('RtxModifier doing nothing, no video ssrcs present');
 
             return false;
         }
-        logger.debug('Current ssrc mapping: ', this.correspondingRtxSsrcs);
         const primaryVideoSsrcs = videoMLine.getPrimaryVideoSSRCs();
 
-        logger.debug('Parsed primary video ssrcs ', primaryVideoSsrcs,
-            ' making sure all have rtx streams');
         for (const ssrc of primaryVideoSsrcs) {
             const msid = videoMLine.getSSRCAttrValue(ssrc, 'msid');
             const cname = videoMLine.getSSRCAttrValue(ssrc, 'cname');
             let correspondingRtxSsrc = this.correspondingRtxSsrcs.get(ssrc);
 
-            if (correspondingRtxSsrc) {
-                logger.debug(
-                    'Already have an associated rtx ssrc for '
-                    + `video ssrc ${ssrc}: ${correspondingRtxSsrc}`);
-            } else {
-                logger.debug(
-                    `No previously associated rtx ssrc for video ssrc ${ssrc}`);
-
+            if (!correspondingRtxSsrc) {
                 // If there's one in the sdp already for it, we'll just set
                 //  that as the corresponding one
                 const previousAssociatedRtxStream = videoMLine.getRtxSSRC(ssrc);
 
                 if (previousAssociatedRtxStream) {
-                    logger.debug(
-                        `Rtx stream ${previousAssociatedRtxStream} `
-                        + 'already existed in the sdp as an rtx stream for '
-                        + `${ssrc}`);
                     correspondingRtxSsrc = previousAssociatedRtxStream;
                 } else {
                     correspondingRtxSsrc = SDPUtil.generateSsrc();
-                    logger.debug(`Generated rtx ssrc ${correspondingRtxSsrc} `
-                                 + `for ssrc ${ssrc}`);
                 }
-                logger.debug(`Caching rtx ssrc ${correspondingRtxSsrc} `
-                             + `for video ssrc ${ssrc}`);
                 this.correspondingRtxSsrcs.set(ssrc, correspondingRtxSsrc);
             }
             updateAssociatedRtxStream(

modules/sdp/SdpConsistency.js

@@ -77,9 +77,7 @@ export default class SdpConsistency {
         const videoMLine = sdpTransformer.selectMedia('video');
 
         if (!videoMLine) {
-            logger.debug(
-                `${this.logPrefix} no 'video' media found in the sdp: `
-                    + `${sdpStr}`);
+            logger.debug(`${this.logPrefix} no 'video' media found in the sdp: ${sdpStr}`);
 
             return sdpStr;
         }
@@ -94,25 +92,17 @@ export default class SdpConsistency {
                     value: `recvonly-${this.cachedPrimarySsrc}`
                 });
             } else {
-                logger.info(
-                    `${this.logPrefix} no SSRC found for the recvonly video`
-                        + 'stream!');
+                logger.info(`${this.logPrefix} no SSRC found for the recvonly video stream!`);
             }
         } else {
             const newPrimarySsrc = videoMLine.getPrimaryVideoSsrc();
 
             if (!newPrimarySsrc) {
-                logger.info(
-                    `${this.logPrefix} sdp-consistency couldn't`
-                        + ' parse new primary ssrc');
+                logger.info(`${this.logPrefix} sdp-consistency couldn't parse new primary ssrc`);
 
                 return sdpStr;
             }
             if (this.cachedPrimarySsrc) {
-                logger.info(
-                    `${this.logPrefix} sdp-consistency replacing new ssrc`
-                        + `${newPrimarySsrc} with cached `
-                        + `${this.cachedPrimarySsrc}`);
                 videoMLine.replaceSSRC(newPrimarySsrc, this.cachedPrimarySsrc);
                 for (const group of videoMLine.ssrcGroups) {
                     if (group.semantics === 'FID') {
@@ -128,11 +118,7 @@ export default class SdpConsistency {
                 }
             } else {
                 this.cachedPrimarySsrc = newPrimarySsrc;
-                logger.info(
-                    `${this.logPrefix} sdp-consistency caching primary ssrc`
-                        + `${this.cachedPrimarySsrc}`);
             }
-
             this.injectRecvOnly = true;
         }
 

modules/xmpp/JingleSessionPC.js

@@ -453,10 +453,7 @@ export default class JingleSessionPC extends JingleSession {
                     `ice.state.${this.peerconnection.iceConnectionState}`]
                     = now;
             }
-            logger.log(
-                `(TIME) ICE ${this.peerconnection.iceConnectionState}`
-                    + ` P2P? ${this.isP2P}:\t`,
-                now);
+            logger.log(`(TIME) ICE ${this.peerconnection.iceConnectionState} ${this.isP2P ? 'P2P' : 'JVB'}:\t`, now);
 
             Statistics.sendAnalytics(
                 ICE_STATE_CHANGED,
@@ -793,8 +790,7 @@ export default class JingleSessionPC extends JingleSession {
             });
 
         if (!iceCandidates.length) {
-            logger.error(
-                'No ICE candidates to add ?', elem[0] && elem[0].outerHTML);
+            logger.error('No ICE candidates to add ?', elem[0] && elem[0].outerHTML);
 
             return;
         }
@@ -815,8 +811,7 @@ export default class JingleSessionPC extends JingleSession {
             logger.debug(`ICE candidates task finished on ${this}`);
         };
 
-        logger.debug(
-            `Queued add (${iceCandidates.length}) ICE candidates task...`);
+        logger.debug(`Queued add (${iceCandidates.length}) ICE candidates task...`);
         this.modificationQueue.push(workFunction);
     }
 
@@ -845,9 +840,7 @@ export default class JingleSessionPC extends JingleSession {
 
                         if (owner && owner.length) {
                             if (isNaN(ssrc) || ssrc < 0) {
-                                logger.warn(
-                                    `Invalid SSRC ${ssrc} value received`
-                                        + ` for ${owner}`);
+                                logger.warn(`Invalid SSRC ${ssrc} value received for ${owner}`);
                             } else {
                                 this.signalingLayer.setSSRCOwner(
                                     ssrc,
@@ -868,8 +861,7 @@ export default class JingleSessionPC extends JingleSession {
         if (this.peerconnection) {
             this.peerconnection.generateRecvonlySsrc();
         } else {
-            logger.error(
-                'Unable to generate recvonly SSRC - no peerconnection');
+            logger.error('Unable to generate recvonly SSRC - no peerconnection');
         }
     }
 
@@ -1617,8 +1609,7 @@ export default class JingleSessionPC extends JingleSession {
                 const ssrc = $(this).attr('ssrc');
 
                 if (currentRemoteSdp.containsSSRC(ssrc)) {
-                    logger.warn(
-                        `Source-add request for existing SSRC: ${ssrc}`);
+                    logger.warn(`Source-add request for existing SSRC: ${ssrc}`);
 
                     return;
                 }
@@ -1739,12 +1730,8 @@ export default class JingleSessionPC extends JingleSession {
             }
 
             logger.log(`Processing ${logPrefix}`);
-            logger.log(
-                'ICE connection state: ',
-                this.peerconnection.iceConnectionState);
 
-            const oldLocalSdp
-                = new SDP(this.peerconnection.localDescription.sdp);
+            const oldLocalSdp = new SDP(this.peerconnection.localDescription.sdp);
             const sdp = new SDP(this.peerconnection.remoteDescription.sdp);
             const addOrRemoveSsrcInfo
                 = isAdd
@@ -1760,8 +1747,7 @@ export default class JingleSessionPC extends JingleSession {
                     const newLocalSdp
                         = new SDP(this.peerconnection.localDescription.sdp);
 
-                    logger.log(
-                        `${logPrefix} - OK, SDPs: `, oldLocalSdp, newLocalSdp);
+                    logger.log(`${logPrefix} - OK`);
                     this.notifyMySSRCUpdate(oldLocalSdp, newLocalSdp);
                     finishedCallback();
                 }, error => {
@@ -1940,8 +1926,7 @@ export default class JingleSessionPC extends JingleSession {
 
                 return this.peerconnection.setLocalDescription(offer)
                     .then(() => {
-                        logger.debug(
-                            'Renegotiate: setting remote description');
+                        logger.debug('Renegotiate: setting remote description');
 
                         // eslint-disable-next-line max-len
                         return this.peerconnection.setRemoteDescription(remoteDescription);
@@ -2154,9 +2139,7 @@ export default class JingleSessionPC extends JingleSession {
         const addedMedia = sdpDiff.getNewMedia();
 
         if (Object.keys(addedMedia).length) {
-            logger.error(
-                `${this} - some SSRC were added on ${operationName}`,
-                addedMedia);
+            logger.error(`${this} - some SSRC were added on ${operationName}`, addedMedia);
 
             return false;
         }
@@ -2165,9 +2148,7 @@ export default class JingleSessionPC extends JingleSession {
         const removedMedia = sdpDiff.getNewMedia();
 
         if (Object.keys(removedMedia).length) {
-            logger.error(
-                `${this} - some SSRCs were removed on ${operationName}`,
-                removedMedia);
+            logger.error(`${this} - some SSRCs were removed on ${operationName}`, removedMedia);
 
             return false;
         }
@@ -2432,8 +2413,7 @@ export default class JingleSessionPC extends JingleSession {
                 || (remoteVideoSenders === 'responder' && !this.isInitiator);
 
         if (isRemoteVideoActive !== this._remoteVideoActive) {
-            logger.debug(
-                `${this} new remote video active: ${isRemoteVideoActive}`);
+            logger.debug(`${this} new remote video active: ${isRemoteVideoActive}`);
             this._remoteVideoActive = isRemoteVideoActive;
         }
 
@@ -2627,8 +2607,7 @@ export default class JingleSessionPC extends JingleSession {
      * @return {string}
      */
     toString() {
-        return `JingleSessionPC[p2p=${this.isP2P},`
-                    + `initiator=${this.isInitiator},sid=${this.sid}]`;
+        return `JingleSessionPC[${this.isP2P ? 'P2P' : 'JVB'},initiator=${this.isInitiator},sid=${this.sid}]`;
     }
 
     /**

modules/xmpp/strophe.jingle.js

@@ -71,7 +71,7 @@ export default class JingleConnectionPlugin extends ConnectionPlugin {
             id: iq.getAttribute('id')
         });
 
-        logger.log(`on jingle ${action} from ${fromJid}`, iq);
+        logger.log(`on jingle ${action} from ${fromJid}`, JSON.stringify(iq));
         let sess = this.sessions[sid];
 
         if (action !== 'session-initiate') {