From a3a5d2f6a4a9c0db4323e05e118dcd945b43c2d3 Mon Sep 17 00:00:00 2001 From: prlanzarin <prlanzarin@inf.ufrgs.br> Date: Mon, 15 Jul 2019 20:59:00 +0000 Subject: [PATCH] Refactor screenshare/listen only client-side logs --- .../api/audio/client/bridge/kurento.js | 42 +--- .../api/screenshare/client/bridge/kurento.js | 34 +-- .../public/compatibility/kurento-extension.js | 200 ++++++++++-------- 3 files changed, 123 insertions(+), 153 deletions(-) diff --git a/bigbluebutton-html5/imports/api/audio/client/bridge/kurento.js b/bigbluebutton-html5/imports/api/audio/client/bridge/kurento.js index 973ca24610..18dd529dbb 100755 --- a/bigbluebutton-html5/imports/api/audio/client/bridge/kurento.js +++ b/bigbluebutton-html5/imports/api/audio/client/bridge/kurento.js @@ -8,34 +8,6 @@ const MEDIA = Meteor.settings.public.media; const MEDIA_TAG = MEDIA.mediaTag.replace(/#/g, ''); const GLOBAL_AUDIO_PREFIX = 'GLOBAL_AUDIO_'; -const logFunc = (type, message, options) => { - const topic = options.topic || 'audio'; - - logger[type]({ - logCode: 'TODO_kurento_audio', - extraInfo: { - topic, - message, - options, - }, - }, options && options.message && options.message.id ? options.message.id : 'kurento audio'); -}; - -const modLogger = { - info(message, options = {}) { - if (message.id !== 'ping' && options.message && options.message.id !== 'ping') logFunc('info', message, options); - }, - error(message, options = {}) { - logFunc('error', message, options); - }, - debug(message, options = {}) { - logFunc('debug', message, options); - }, - warn: (message, options = {}) => { - logFunc('warn', message, options); - }, -}; - export default class KurentoAudioBridge extends BaseAudioBridge { constructor(userData) { super(); @@ -70,15 +42,17 @@ export default class KurentoAudioBridge extends BaseAudioBridge { try { iceServers = await fetchWebRTCMappedStunTurnServers(this.user.sessionToken); } catch (error) { - logFunc('error', 'SFU audio bridge failed to fetch STUN/TURN info, using default'); + logger.error({ logCode: 'sfuaudiobridge_stunturn_fetch_failed' }, + 'SFU audio bridge failed to fetch STUN/TURN info, using default servers'); } finally { - logFunc('info', 'iceServers', iceServers); + logger.debug({ logCode: 'sfuaudiobridge_stunturn_fetch_sucess', extraInfo: { iceServers } }, + "SFU audio bridge got STUN/TURN servers"); const options = { wsUrl: Auth.authenticateURL(SFU_URL), userName: this.user.name, caleeName: `${GLOBAL_AUDIO_PREFIX}${this.voiceBridge}`, iceServers, - logger: modLogger, + logger, inputStream, }; @@ -132,9 +106,9 @@ export default class KurentoAudioBridge extends BaseAudioBridge { try { await audioContext.setSinkId(value); this.media.outputDeviceId = value; - } catch (err) { - logFunc('error', 'SFU audio bridge failed to fetch STUN/TURN info, using default', - { logCode: 'audio_kurento_changeoutputdevice_error', err }); + } catch (error) { + logger.error({logCode: 'sfuaudiobridge_changeoutputdevice_error', extraInfo: { error }}, + 'SFU audio bridge failed to fetch STUN/TURN info, using default'); throw new Error(this.baseErrorCodes.MEDIA_ERROR); } } diff --git a/bigbluebutton-html5/imports/api/screenshare/client/bridge/kurento.js b/bigbluebutton-html5/imports/api/screenshare/client/bridge/kurento.js index 52ee3313b0..71c29613c9 100755 --- a/bigbluebutton-html5/imports/api/screenshare/client/bridge/kurento.js +++ b/bigbluebutton-html5/imports/api/screenshare/client/bridge/kurento.js @@ -22,30 +22,6 @@ const getUsername = () => Users.findOne({ userId: getUserId() }).name; const getSessionToken = () => Auth.sessionToken; -const logFunc = (type, message, options) => { - const userId = getUserId(); - const userName = getUsername(); - - const topic = options.topic || 'screenshare'; - - logger[type]({ obj: Object.assign(options, { userId, userName, topic }) }, `[${topic}] ${message}`); -}; - -const modLogger = { - info(message, options = {}) { - logFunc('info', message, options); - }, - error(message, options = {}) { - logFunc('error', message, options); - }, - debug(message, options = {}) { - logFunc('debug', message, options); - }, - warn: (message, options = {}) => { - logFunc('warn', message, options); - }, -}; - export default class KurentoScreenshareBridge { async kurentoWatchVideo() { let iceServers = []; @@ -53,12 +29,13 @@ export default class KurentoScreenshareBridge { try { iceServers = await fetchWebRTCMappedStunTurnServers(getSessionToken()); } catch (error) { - logger.error({ logCode: 'kurentowatchvideo_fetchstunturninfo_error' }, 'Screenshare bridge failed to fetch STUN/TURN info, using default'); + logger.error({ logCode: 'sfuviewscreen_fetchstunturninfo_error', extraInfo: { error } }, + 'Screenshare bridge failed to fetch STUN/TURN info, using default'); } finally { const options = { wsUrl: Auth.authenticateURL(SFU_URL), iceServers, - logger: modLogger, + logger, }; window.kurentoWatchVideo( @@ -82,7 +59,8 @@ export default class KurentoScreenshareBridge { try { iceServers = await fetchWebRTCMappedStunTurnServers(getSessionToken()); } catch (error) { - logger.error({ logCode: 'kurentosharescreen_fetchstunturninfo_error' }, 'Screenshare bridge failed to fetch STUN/TURN info, using default'); + logger.error({ logCode: 'sfusharescreen_fetchstunturninfo_error' }, + 'Screenshare bridge failed to fetch STUN/TURN info, using default'); } finally { const options = { wsUrl: Auth.authenticateURL(SFU_URL), @@ -90,7 +68,7 @@ export default class KurentoScreenshareBridge { chromeScreenshareSources: CHROME_SCREENSHARE_SOURCES, firefoxScreenshareSource: FIREFOX_SCREENSHARE_SOURCE, iceServers, - logger: modLogger, + logger, }; window.kurentoShareScreen( SCREENSHARE_VIDEO_TAG, diff --git a/bigbluebutton-html5/public/compatibility/kurento-extension.js b/bigbluebutton-html5/public/compatibility/kurento-extension.js index 729c4954f5..a20cd35b42 100755 --- a/bigbluebutton-html5/public/compatibility/kurento-extension.js +++ b/bigbluebutton-html5/public/compatibility/kurento-extension.js @@ -27,7 +27,7 @@ Kurento = function ( this.internalMeetingId = internalMeetingId; // Optional parameters are: userName, caleeName, chromeExtension, wsUrl, iceServers, - // chromeScreenshareSources, firefoxScreenshareSource + // chromeScreenshareSources, firefoxScreenshareSource, logger Object.assign(this, options); @@ -66,13 +66,14 @@ Kurento = function ( this.pingInterval = null; - + // TODO FIXME we need to implement a handleError method to normalize errors + // generated in this script if (onFail != null) { this.onFail = Kurento.normalizeCallback(onFail); } else { const _this = this; this.onFail = function () { - _this.logError('Default error handler'); + _this.logger.error('Default error handler'); }; } @@ -81,7 +82,7 @@ Kurento = function ( } else { const _this = this; this.onSuccess = function () { - _this.logger('Default success handler'); + _this.logger.info('Default success handler'); }; } }; @@ -95,7 +96,8 @@ this.KurentoManager = function () { KurentoManager.prototype.exitScreenShare = function () { if (typeof this.kurentoScreenshare !== 'undefined' && this.kurentoScreenshare) { if (this.kurentoScreenshare.logger !== null) { - this.kurentoScreenshare.logger.info(' [exitScreenShare] Exiting screensharing'); + this.kurentoScreenshare.logger.info({ logCode: 'kurentoextension_exit_screenshare_presenter' }, + 'Exiting screensharing as presenter'); } if(this.kurentoScreenshare.webRtcPeer) { @@ -124,7 +126,8 @@ KurentoManager.prototype.exitVideo = function () { } if (this.kurentoVideo.logger !== null) { - this.kurentoVideo.logger.info(' [exitScreenShare] Exiting screensharing viewing'); + this.kurentoScreenshare.logger.info({ logCode: 'kurentoextension_exit_screenshare_viewer' }, + 'Exiting screensharing as viewer'); } if (this.kurentoVideo.ws !== null) { @@ -151,7 +154,8 @@ KurentoManager.prototype.exitVideo = function () { KurentoManager.prototype.exitAudio = function () { if (typeof this.kurentoAudio !== 'undefined' && this.kurentoAudio) { if (this.kurentoAudio.logger !== null) { - this.kurentoAudio.logger.info(' [exitAudio] Exiting listen only audio'); + this.kurentoAudio.logger.info({ logCode: 'kurentoextension_exit_listen_only' }, + 'Exiting listen only'); } if (this.kurentoAudio.ws !== null) { @@ -228,23 +232,31 @@ Kurento.prototype.downscaleResolution = function (oldWidth, oldHeight) { Kurento.prototype.init = function () { const self = this; if ('WebSocket' in window) { - this.logger.info('this browser supports websockets'); this.ws = new WebSocket(this.wsUrl); this.ws.onmessage = this.onWSMessage.bind(this); this.ws.onclose = () => { kurentoManager.exitScreenShare(); + this.logger.error({ logCode: 'kurentoextension_websocket_close' }, + 'WebSocket connection to SFU closed unexpectedly, screenshare/listen only will drop'); self.onFail('Websocket connection closed'); }; this.ws.onerror = (error) => { kurentoManager.exitScreenShare(); + this.logger.error({ + logCode: 'kurentoextension_websocket_error', + extraInfo: { error } + }, `Error in the WebSocket connection to SFU, screenshare/listen only will drop due to ${error.message$}`); self.onFail('Websocket connection error'); }; this.ws.onopen = function () { self.pingInterval = setInterval(self.ping.bind(self), self.PING_INTERVAL); self.mediaCallback(); }; - } else { this.logger.info('this browser does not support websockets'); } + } else { + this.logger.info({ logCode: 'kurentoextension_websocket_unsupported'}, + 'Browser does not support websockets'); + } }; Kurento.prototype.onWSMessage = function (message) { @@ -268,7 +280,10 @@ Kurento.prototype.onWSMessage = function (message) { case 'pong': break; default: - this.logger.error('Unrecognized message', parsedMessage); + this.logger.error({ + logCode: 'kurentoextension_unrecognized_sfu_message', + extraInfo: { sfuResponse: parsedMessage } + }, `Unrecognized SFU message: ${parsedMessage.id}`); } }; @@ -278,10 +293,14 @@ Kurento.prototype.setRenderTag = function (tag) { Kurento.prototype.startResponse = function (message) { if (message.response !== 'accepted') { - const errorMsg = message.message ? message.message : 'Unknow error'; - this.logger.warn('Call not accepted for the following reason:', { error: errorMsg }); + const { code, reason } = message; switch (message.type) { case 'screenshare': + this.logger.error({ + logCode: 'kurentoextension_screenshare_start_rejected', + extraInfo: { sfuResponse: message } + }, `SFU screenshare rejected by SFU with error ${ code, reason }`); + if (message.role === this.SEND_ROLE) { kurentoManager.exitScreenShare(); } else if (message.role === this.RECV_ROLE) { @@ -289,11 +308,19 @@ Kurento.prototype.startResponse = function (message) { } break; case 'audio': + this.logger.error({ + logCode: 'kurentoextension_listenonly_start_rejected', + extraInfo: { sfuResponse: message } + }, `SFU listen only rejected by SFU with error ${ code, reason }`); + kurentoManager.exitAudio(); break; } } else { - this.logger.debug(`Procedure for ${message.type} was accepted with SDP =>`, { sdpAnswer: message.sdpAnswer }); + this.logger.info({ + logCode: 'kurentoextension_start_success', + extraInfo: { sfuResponse: message } + }, `Start request accepted for ${message.type}`); this.webRtcPeer.processAnswer(message.sdpAnswer); } }; @@ -302,7 +329,10 @@ Kurento.prototype.onOfferPresenter = function (error, offerSdp) { const self = this; if (error) { - this.logger.info(`Kurento.prototype.onOfferPresenter Error ${error}`); + this.logger.error({ + logCode: 'kurentoextension_screenshare_presenter_offer_failure', + extraInfo: { error } + }, `Failed to generate peer connection offer for screenshare presenter with error ${error.message}`); this.onFail(error); return; } @@ -319,18 +349,22 @@ Kurento.prototype.onOfferPresenter = function (error, offerSdp) { vw: this.width, }; - this.logger.info('onOfferPresenter sending to screenshare server => ', { sdpOffer: message }); + this.logger.info({ + logCode: 'kurentoextension_screenshare_request_start_presenter' , + extraInfo: { sfuRequest: message }, + }, `Screenshare presenter offer generated. Sending start request to SFU`); + this.sendMessage(message); }; Kurento.prototype.startScreensharing = function () { if (window.chrome) { - if (this.chromeExtension == null) { - this.logError({ - status: 'failed', - message: 'Missing Chrome Extension key', - }); + if (this.chromeExtension == null && !hasDisplayMedia) { + this.logger.error({ logCode: "kurentoextension_screenshare_noextensionkey" }, + 'Screenshare hasnt got a Chrome extension key configured', + ); + // TODO error handling here this.onFail(); return; } @@ -344,28 +378,30 @@ Kurento.prototype.startScreensharing = function () { sendSource: 'desktop', }; - this.logger.info(' Peer options =>', options); - let resolution; - this.logger.debug(`Screenshare screen dimensions are ${this.width} x ${this.height}`); + this.logger.debug({ logCode: 'kurentoextension_screenshare_screen_dimensions'}, + `Screenshare screen dimensions are ${this.width} x ${this.height}`); if (this.width > this.vid_max_width || this.height > this.vid_max_height) { resolution = this.downscaleResolution(this.width, this.height); this.width = resolution.width; this.height = resolution.height; - this.logger.debug('Screenshare track dimensions have been resized to', this.width, 'x', this.height); + this.logger.info({ logCode: 'kurentoextension_screenshare_track_resize' }, + `Screenshare track dimensions have been resized to ${this.width} x ${this.height}`); } this.addIceServers(this.iceServers, options); this.webRtcPeer = kurentoUtils.WebRtcPeer.WebRtcPeerSendonly(options, (error) => { if (error) { - this.logger.error('WebRtcPeerSendonly constructor error:', { error }); + this.logger.error({ + logCode: 'kurentoextension_screenshare_peerconnection_create_error', + extraInfo: { error } + }, `WebRTC peer constructor for screenshare (presenter) failed due to ${error.message}`); this.onFail(error); return kurentoManager.exitScreenShare(); } this.webRtcPeer.generateOffer(this.onOfferPresenter.bind(this)); - this.logger.info('Generated peer offer w/ options:', { options }); const localStream = this.webRtcPeer.peerConnection.getLocalStreams()[0]; const _this = this; @@ -380,9 +416,13 @@ Kurento.prototype.startScreensharing = function () { }); this.webRtcPeer.peerConnection.oniceconnectionstatechange = () => { if (this.webRtcPeer) { - const connectionState = this.webRtcPeer.peerConnection.iceConnectionState; - if (connectionState === 'failed' || connectionState === 'closed') { + const iceConnectionState = this.webRtcPeer.peerConnection.iceConnectionState; + if (iceConnectionState === 'failed' || iceConnectionState === 'closed') { this.webRtcPeer.peerConnection.oniceconnectionstatechange = null; + this.logger.error({ + logCode: 'kurentoextension_screenshare_presenter_ice_failed', + extraInfo: { iceConnectionState } + }, `WebRTC peer for screenshare presenter failed due to ICE transitioning to ${iceConnectionState}`); this.onFail('ICE connection failed'); } } @@ -391,7 +431,10 @@ Kurento.prototype.startScreensharing = function () { Kurento.prototype.onIceCandidate = function (candidate, role) { const self = this; - this.logger.info('Local candidate:', { candidate }); + this.logger.debug({ + logCode: 'kurentoextension_screenshare_client_candidate', + extraInfo: { candidate } + }, `Screenshare client-side candidate generated: ${JSON.stringify(candidate)}`); const message = { id: this.ON_ICE_CANDIDATE_MSG, @@ -437,9 +480,13 @@ Kurento.prototype.viewer = function () { }); self.webRtcPeer.peerConnection.oniceconnectionstatechange = () => { if (this.webRtcPeer) { - const connectionState = this.webRtcPeer.peerConnection.iceConnectionState; - if (connectionState === 'failed' || connectionState === 'closed') { + const iceConnectionState = this.webRtcPeer.peerConnection.iceConnectionState; + if (iceConnectionState === 'failed' || iceConnectionState === 'closed') { this.webRtcPeer.peerConnection.oniceconnectionstatechange = null; + this.logger.error({ + logCode: 'kurentoextension_screenshare_viewer_ice_failed', + extraInfo: { iceConnectionState } + }, `WebRTC peer for screenshare viewer failed due to ICE transitioning to ${iceConnectionState}`); this.onFail('ICE connection failed'); } } @@ -450,9 +497,14 @@ Kurento.prototype.viewer = function () { Kurento.prototype.onOfferViewer = function (error, offerSdp) { const self = this; if (error) { - this.logger.info(`Kurento.prototype.onOfferViewer Error ${error}`); - return this.onFail(); + this.logger.error({ + logCode: 'kurentoextension_screenshare_viewer_offer_failure', + extraInfo: { error } + }, `Failed to generate peer connection offer for screenshare viewer with error ${error.message}`); + + return this.onFail(error); } + const message = { id: 'start', type: this.SFU_APP, @@ -463,7 +515,11 @@ Kurento.prototype.onOfferViewer = function (error, offerSdp) { sdpOffer: offerSdp, }; - this.logger.info('onOfferViewer sending to screenshare server: ', { sdpOffer: message.sdpOffer }); + this.logger.info({ + logCode: 'kurentoextension_screenshare_request_start_viewer', + extraInfo: { sfuRequest: message }, + }, `Screenshare viewer offer generated. Sending start request to SFU`); + this.sendMessage(message); }; @@ -505,7 +561,10 @@ Kurento.prototype.listenOnly = function () { Kurento.prototype.onListenOnlyIceCandidate = function (candidate) { const self = this; - this.logger.debug('[onListenOnlyIceCandidate]', { candidate }); + this.logger.debug({ + logCode: 'kurentoextension_listenonly_client_candidate', + extraInfo: { candidate } + }, `Listen only client-side candidate generated: ${JSON.stringify(candidate)}`); const message = { id: this.ON_ICE_CANDIDATE_MSG, @@ -520,7 +579,11 @@ Kurento.prototype.onListenOnlyIceCandidate = function (candidate) { Kurento.prototype.onOfferListenOnly = function (error, offerSdp) { const self = this; if (error) { - this.logger.error('[onOfferListenOnly]', error); + this.logger.error({ + logCode: 'kurentoextension_listenonly_offer_failure', + extraInfo: { error } + }, `Failed to generate peer connection offer for listen only with error ${error.message}`); + return this.onFail(error); } @@ -536,7 +599,10 @@ Kurento.prototype.onOfferListenOnly = function (error, offerSdp) { internalMeetingId: self.internalMeetingId, }; - this.logger.debug('[onOfferListenOnly]', { message }); + this.logger.info({ + logCode: 'kurentoextension_listenonly_request_start', + extraInfo: { sfuRequest: message }, + }, "Listen only offer generated. Sending start request to SFU"); this.sendMessage(message); }; @@ -559,8 +625,12 @@ Kurento.prototype.resumeTrack = function (message) { }; Kurento.prototype.addIceServers = function (iceServers, options) { - this.logger.debug('Adding iceServers', iceServers); if (iceServers && iceServers.length > 0) { + this.logger.debug({ + logCode: 'kurentoextension_add_iceservers', + extraInfo: { iceServers } + }, `Injecting ICE servers into peer creation`); + options.configuration = {}; options.configuration.iceServers = iceServers; } @@ -594,29 +664,19 @@ Kurento.prototype.ping = function () { Kurento.prototype.sendMessage = function (message) { const jsonMessage = JSON.stringify(message); - this.logger.info('Sending message:', { message }); this.ws.send(jsonMessage); }; -Kurento.prototype.logger = function (obj) { - this.logger.info(obj); -}; - -Kurento.prototype.logError = function (obj) { - this.logger.error(obj); -}; - - Kurento.normalizeCallback = function (callback) { if (typeof callback === 'function') { return callback; } - this.logger.info(document.getElementById('BigBlueButton')[callback]); return function (args) { document.getElementById('BigBlueButton')[callback](args); }; }; + /* Global methods */ // this function explains how to use above methods/objects @@ -682,7 +742,6 @@ window.getScreenConstraints = function (sendSource, callback) { screenConstraints.video.chromeMediaSourceId = sourceId; screenConstraints.optional = optionalConstraints; - console.log('getScreenConstraints for Chrome returns => ', screenConstraints); return callback(null, screenConstraints); } @@ -709,7 +768,6 @@ window.getScreenConstraints = function (sendSource, callback) { screenConstraints.video.mandatory.chromeMediaSourceId = sourceId; screenConstraints.optional = optionalConstraints; - console.log('getScreenConstraints for Chrome returns => ', screenConstraints); return callback(null, screenConstraints); }); } else { @@ -720,8 +778,6 @@ window.getScreenConstraints = function (sendSource, callback) { if (isFirefox) { const firefoxScreenshareSource = kurentoManager.getFirefoxScreenshareSource(); screenConstraints.video.mediaSource = firefoxScreenshareSource; - - console.log('getScreenConstraints for Firefox returns => ', screenConstraints); return callback(null, screenConstraints); } @@ -772,41 +828,3 @@ window.kurentoExitAudio = function () { window.kurentoInitialize(); window.kurentoManager.exitAudio(); }; - -// a function to check whether the browser (Chrome only) is in an isIncognito -// session. Requires 1 mandatory callback that only gets called if the browser -// session is incognito. The callback for not being incognito is optional. -// Attempts to retrieve the chrome filesystem API. -/* window.checkIfIncognito = function(isIncognito, isNotIncognito = function () {}) { - isIncognito = Kurento.normalizeCallback(isIncognito); - isNotIncognito = Kurento.normalizeCallback(isNotIncognito); - - var fs = window.RequestFileSystem || window.webkitRequestFileSystem; - if (!fs) { - isNotIncognito(); - return; - } - fs(window.TEMPORARY, 100, function(){isNotIncognito()}, function(){isIncognito()}); -}; - -window.checkChromeExtInstalled = function (callback, chromeExtensionId) { - callback = Kurento.normalizeCallback(callback); - - if (typeof chrome === "undefined" || !chrome || !chrome.runtime) { - // No API, so no extension for sure - callback(false); - return; - } - chrome.runtime.sendMessage( - chromeExtensionId, - { getVersion: true }, - function (response) { - if (!response || !response.version) { - // Communication failure - assume that no endpoint exists - callback(false); - return; - } - callback(true); - } - ); -} */ -- GitLab