fix(modificationQueue): error handling & logs

JitsiConference.js

@@ -1127,7 +1127,8 @@ JitsiConference.prototype.replaceTrack = function(oldTrack, newTrack) {
             }
 
             return Promise.resolve();
-        }, error => Promise.reject(new Error(error)));
+        })
+        .catch(error => Promise.reject(new Error(error)));
 };
 
 /**

modules/RTC/TPCUtils.js

@@ -366,6 +366,8 @@ export class TPCUtils {
                 });
         }
 
+        logger.info('TPCUtils.replaceTrack called with no new track and no old track');
+
         return Promise.resolve();
     }
 

modules/RTC/TraceablePeerConnection.js

@@ -1878,12 +1878,16 @@ TraceablePeerConnection.prototype.findSenderForTrack = function(track) {
  */
 TraceablePeerConnection.prototype.replaceTrack = function(oldTrack, newTrack) {
     if (browser.usesUnifiedPlan()) {
+        logger.debug('TPC.replaceTrack using unified plan.');
+
         return this.tpcUtils.replaceTrack(oldTrack, newTrack)
 
             // renegotiate when SDP is used for simulcast munging
             .then(() => this.isSimulcastOn() && browser.usesSdpMungingForSimulcast());
     }
 
+    logger.debug('TPC.replaceTrack using plan B.');
+
     let promiseChain = Promise.resolve();
 
     if (oldTrack) {

modules/util/AsyncQueue.js

@@ -1,4 +1,9 @@
+/* global __filename */
+
 import async from 'async';
+import { getLogger } from 'jitsi-meet-logger';
+
+const logger = getLogger(__filename);
 
 /**
  * A queue for async task execution.
@@ -23,7 +28,12 @@ export default class AsyncQueue {
      * Internal task processing implementation which makes things work.
      */
     _processQueueTasks(task, finishedCallback) {
-        task(finishedCallback);
+        try {
+            task(finishedCallback);
+        } catch (error) {
+            logger.error(`Task failed: ${error}`);
+            finishedCallback(error);
+        }
     }
 
     /**

modules/xmpp/JingleSessionPC.js

@@ -566,9 +566,9 @@ export default class JingleSessionPC extends JingleSession {
                     workFunction,
                     error => {
                         if (error) {
-                            logger.error('onnegotiationneeded error', error);
+                            logger.error(`onnegotiationneeded error on ${this}`, error);
                         } else {
-                            logger.debug('onnegotiationneeded executed - OK');
+                            logger.debug(`onnegotiationneeded executed - OK on ${this}`);
                         }
                     });
             }
@@ -811,6 +811,7 @@ export default class JingleSessionPC extends JingleSession {
             }
 
             finishedCallback();
+            logger.debug(`ICE candidates task finished on ${this}`);
         };
 
         logger.debug(
@@ -941,13 +942,14 @@ export default class JingleSessionPC extends JingleSession {
                 .then(() => finishedCallback(), error => finishedCallback(error));
         };
 
+        logger.debug(`Queued invite task on ${this}.`);
         this.modificationQueue.push(
             workFunction,
             error => {
                 if (error) {
-                    logger.error('invite error', error);
+                    logger.error(`invite error on ${this}`, error);
                 } else {
-                    logger.debug('invite executed - OK');
+                    logger.debug(`invite executed - OK on ${this}`);
                 }
             });
     }
@@ -1084,10 +1086,17 @@ export default class JingleSessionPC extends JingleSession {
                 .then(() => finishedCallback(), error => finishedCallback(error));
         };
 
+        logger.debug(`Queued setOfferAnswerCycle task on ${this}`);
         this.modificationQueue.push(
             workFunction,
             error => {
-                error ? failure(error) : success();
+                if (error) {
+                    logger.error(`setOfferAnswerCycle task on ${this} failed: ${error}`);
+                    failure(error);
+                } else {
+                    logger.debug(`setOfferAnswerCycle task on ${this} done.`);
+                    success();
+                }
             });
     }
 
@@ -1107,9 +1116,20 @@ export default class JingleSessionPC extends JingleSession {
 
             // Initiate a renegotiate for the codec setting to take effect.
             const workFunction = finishedCallback => {
-                this._renegotiate().then(() => finishedCallback(), error => finishedCallback(error));
+                this._renegotiate().then(
+                    () => {
+                        logger.debug(`setVideoCodecs task on ${this} is done.`);
+
+                        return finishedCallback();
+                    }, error => {
+                        logger.error(`setVideoCodecs task on ${this} failed: ${error}`);
+
+                        return finishedCallback(error);
+                    });
             };
 
+            logger.debug(`Queued setVideoCodecs task on ${this}`);
+
             // Queue and execute
             this.modificationQueue.push(workFunction);
         }
@@ -1700,6 +1720,8 @@ export default class JingleSessionPC extends JingleSession {
                 });
         };
 
+        logger.debug(`Queued ${logPrefix} task on ${this}`);
+
         // Queue and execute
         this.modificationQueue.push(workFunction);
     }
@@ -1891,6 +1913,8 @@ export default class JingleSessionPC extends JingleSession {
      */
     replaceTrack(oldTrack, newTrack) {
         const workFunction = finishedCallback => {
+            logger.debug(`replaceTrack worker started. oldTrack = ${oldTrack}, newTrack = ${newTrack}, ${this}`);
+
             const oldLocalSdp = this.peerconnection.localDescription.sdp;
 
             if (browser.usesPlanB()) {
@@ -1932,6 +1956,9 @@ export default class JingleSessionPC extends JingleSession {
                 .then(shouldRenegotiate => {
                     let promise = Promise.resolve();
 
+                    logger.debug(`TPC.replaceTrack finished. shouldRenegotiate = ${
+                        shouldRenegotiate}, JingleSessionState = ${this.state}, ${this}`);
+
                     if (shouldRenegotiate
                         && (oldTrack || newTrack)
                         && this.state === JingleSessionState.ACTIVE) {
@@ -1944,13 +1971,23 @@ export default class JingleSessionPC extends JingleSession {
 
                     return promise.then(() => {
                         if (newTrack && newTrack.isVideoTrack()) {
+                            logger.debug(`replaceTrack worker: setSenderVideoDegradationPreference(), ${this}`);
+
                             // FIXME set all sender parameters in one go?
                             // Set the degradation preference on the new video sender.
                             return this.peerconnection.setSenderVideoDegradationPreference()
 
                                 // Apply the cached video constraints on the new video sender.
-                                .then(() => this.peerconnection.setSenderVideoConstraint())
-                                .then(() => this.peerconnection.setMaxBitRate());
+                                .then(() => {
+                                    logger.debug(`replaceTrack worker: setSenderVideoConstraint(), ${this}`);
+
+                                    return this.peerconnection.setSenderVideoConstraint();
+                                })
+                                .then(() => {
+                                    logger.debug(`replaceTrack worker: setMaxBitRate(), ${this}`);
+
+                                    return this.peerconnection.setMaxBitRate();
+                                });
                         }
                     });
                 })
@@ -1958,14 +1995,17 @@ export default class JingleSessionPC extends JingleSession {
         };
 
         return new Promise((resolve, reject) => {
+            logger.debug(`Queued replaceTrack task. Old track = ${
+                oldTrack}, new track = ${newTrack}, ${this}`);
+
             this.modificationQueue.push(
                 workFunction,
                 error => {
                     if (error) {
-                        logger.error('Replace track error:', error);
+                        logger.error(`Replace track error on ${this}:`, error);
                         reject(error);
                     } else {
-                        logger.info('Replace track done!');
+                        logger.info(`Replace track done on ${this}!`);
                         resolve();
                     }
                 });
@@ -2167,13 +2207,21 @@ export default class JingleSessionPC extends JingleSession {
                 finishedCallback /* will be called with an error */);
         };
 
+        logger.debug(`Queued _addRemoveTrackAsMuteUnmute task on ${this}. Operation - ${operationName}`);
+
         return new Promise((resolve, reject) => {
             this.modificationQueue.push(
                 workFunction,
                 error => {
                     if (error) {
+                        logger.error(`_addRemoveTrackAsMuteUnmute failed. Operation - ${
+                            operationName}, peerconnection = ${this}`);
+
                         reject(error);
                     } else {
+                        logger.debug(`_addRemoveTrackAsMuteUnmute done. Operation - ${
+                            operationName}, peerconnection = ${this}`);
+
                         resolve();
                     }
                 });
@@ -2250,8 +2298,10 @@ export default class JingleSessionPC extends JingleSession {
                 workFunction,
                 error => {
                     if (error) {
+                        logger.error(`Make ${logVideoStr}, ${logAudioStr} task failed!`);
                         reject(error);
                     } else {
+                        logger.debug(`Make ${logVideoStr}, ${logAudioStr} task done!`);
                         resolve();
                     }
                 });
@@ -2302,15 +2352,15 @@ export default class JingleSessionPC extends JingleSession {
             }
         };
 
-        logger.debug(
-            `${this} queued "content-modify" task`
-                + `(video senders="${newVideoSenders}")`);
+        logger.debug(`${this} queued "content-modify" task(video senders="${newVideoSenders}")`);
 
         this.modificationQueue.push(
             workFunction,
             error => {
                 if (error) {
-                    logger.error('"content-modify" failed', error);
+                    logger.error(`"content-modify" failed on PC - ${this}`, error);
+                } else {
+                    logger.debug(`"content-modify" task(video senders="${newVideoSenders}") done. PC = ${this}`);
                 }
             });
     }
@@ -2500,9 +2550,12 @@ export default class JingleSessionPC extends JingleSession {
             this.peerconnection.onsignalingstatechange = null;
         }
 
+        logger.debug(`Clearing modificationQueue on ${this}...`);
+
         // Remove any pending tasks from the queue
         this.modificationQueue.clear();
 
+        logger.debug(`Queued PC close task on ${this}...`);
         this.modificationQueue.push(finishCallback => {
             // The signaling layer will remove it's listeners
             this.signalingLayer.setChatRoom(null);
@@ -2510,8 +2563,11 @@ export default class JingleSessionPC extends JingleSession {
             // do not try to close if already closed.
             this.peerconnection && this.peerconnection.close();
             finishCallback();
+            logger.debug(`PC close task on ${this} done!`);
         });
 
+        logger.debug(`Shutdown modificationQueue on ${this}!`);
+
         // No more tasks can go in after the close task
         this.modificationQueue.shutdown();
     }