Merge pull request #7709 from antobinary/logging-structure

Logging structure - add extraInfo: {}
This commit is contained in:
Anton Georgiev 2019-07-02 17:08:48 -04:00 committed by GitHub
commit ed264351d0
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
19 changed files with 512 additions and 139 deletions

View File

@ -11,7 +11,14 @@ const GLOBAL_AUDIO_PREFIX = 'GLOBAL_AUDIO_';
const logFunc = (type, message, options) => {
const topic = options.topic || 'audio';
logger[type](`[${topic}] ${JSON.stringify(message)} options:${JSON.stringify(options)}`);
logger[type]({
logCode: 'TODO_kurento_audio',
extraInfo: {
topic,
message,
options,
},
}, options && options.message && options.message.id ? options.message.id : 'kurento audio');
};
const modLogger = {
@ -126,7 +133,8 @@ export default class KurentoAudioBridge extends BaseAudioBridge {
await audioContext.setSinkId(value);
this.media.outputDeviceId = value;
} catch (err) {
logger.error({ logCode: 'audio_kurento_changeoutputdevice_error' }, err);
logFunc('error', 'SFU audio bridge failed to fetch STUN/TURN info, using default',
{ logCode: 'audio_kurento_changeoutputdevice_error', err });
throw new Error(this.baseErrorCodes.MEDIA_ERROR);
}
}

View File

@ -42,7 +42,10 @@ class SIPSession {
// There will sometimes we erroneous errors put out like timeouts and improper shutdowns,
// but only the first error ever matters
if (this.alreadyErrored) {
logger.info({ logCode: 'sip_js_absorbing_callback_message' }, `Absorbing a redundant callback message. ${JSON.stringify(message)}`);
logger.info({
logCode: 'sip_js_absorbing_callback_message',
extraInfo: { message },
}, 'Absorbing a redundant callback message.');
return;
}
@ -97,7 +100,7 @@ class SIPSession {
const timeout = setInterval(() => {
clearInterval(timeout);
logger.error({ logCode: 'sip_js_transfer_timed_out' }, 'Timeout on transfering from echo test to conference');
logger.error({ logCode: 'sip_js_transfer_timed_out' }, 'Timeout on transferring from echo test to conference');
this.callback({
status: this.baseCallStates.failed,
error: 1008,
@ -188,15 +191,15 @@ class SIPSession {
// translation
const isSafari = browser().name === 'safari';
logger.debug('Creating the user agent');
logger.debug({ logCode: 'sip_js_creating_user_agent' }, 'Creating the user agent');
if (this.userAgent && this.userAgent.isConnected()) {
if (this.userAgent.configuration.hostPortParams === this.hostname) {
logger.debug('Reusing the user agent');
logger.debug({ logCode: 'sip_js_reusing_user_agent' }, 'Reusing the user agent');
resolve(this.userAgent);
return;
}
logger.debug('different host name. need to kill');
logger.debug({ logCode: 'sip_js_different_host_name' }, 'Different host name. need to kill');
}
let userAgentConnected = false;
@ -348,7 +351,10 @@ class SIPSession {
currentSession.on('progress', handleSessionProgress);
const handleConnectionCompleted = (peer) => {
logger.info({ logCode: 'sip_js_ice_connection_success' }, `ICE connection success. Current state - ${peer.iceConnectionState}`);
logger.info({
logCode: 'sip_js_ice_connection_success',
extraInfo: { currentState: peer.iceConnectionState },
}, `ICE connection success. Current state - ${peer.iceConnectionState}`);
clearTimeout(callTimeout);
clearTimeout(iceNegotiationTimeout);
connectionCompletedEvents.forEach(e => mediaHandler.off(e, handleConnectionCompleted));
@ -369,7 +375,10 @@ class SIPSession {
});
}
logger.error({ logCode: 'sip_js_call_terminated' }, `Audio call terminated. cause=${cause}`);
logger.error({
logCode: 'sip_js_call_terminated',
extraInfo: { cause },
}, `Audio call terminated. cause=${cause}`);
let mappedCause;
if (!iceCompleted) {
@ -592,7 +601,10 @@ export default class SIPBridge extends BaseAudioBridge {
await audioContext.setSinkId(value);
this.media.outputDeviceId = value;
} catch (err) {
logger.error({ logCode: 'audio_sip_changeoutputdevice_error' }, err);
logger.error({
logCode: 'audio_sip_changeoutputdevice_error',
extraInfo: { error: err },
}, 'Change Output Device error');
throw new Error(this.baseErrorCodes.MEDIA_ERROR);
}
}

View File

@ -1,37 +1,30 @@
import Logger from '/imports/startup/server/logger';
import Users from '/imports/api/users';
const logClient = function (type, log, fullInfo = {}) {
const logClient = function (type, logDescription, logCode = 'was_not_provided', extraInfo, userInfo = {}) {
const SERVER_CONN_ID = this.connection.id;
const User = Users.findOne({ connectionId: SERVER_CONN_ID });
const logContents = { fullInfo };
const logContents = {
logCode,
logDescription,
extraInfo,
userInfo,
};
if (User) {
if ((fullInfo.credentials && User.meetingId === fullInfo.credentials.meetingId)
|| ((fullInfo.meetingId && User.meetingId === fullInfo.meetingId))) {
logContents.validUser = 'valid';
if ((userInfo.credentials && User.meetingId === userInfo.credentials.meetingId)
|| ((userInfo.meetingId && User.meetingId === userInfo.meetingId))) {
logContents.extraInfo.validUser = 'valid';
} else {
logContents.validUser = 'invalid';
logContents.extraInfo.validUser = 'invalid';
}
} else {
logContents.validUser = 'notFound';
logContents.extraInfo.validUser = 'notFound';
}
const topic = typeof logContents === 'Object' ? logContents.topic : null;
if (typeof log === 'string' || log instanceof String) {
Logger.log({
level: type,
message: `${topic || 'CLIENT'} LOG: ${log} `,
meta: logContents,
});
} else {
Logger.log({
level: type,
message: `${topic || 'CLIENT'} LOG: ${JSON.stringify(log)} `,
meta: logContents,
});
}
// If I don't pass message, logs will start with `undefined`
Logger.log({ message: JSON.stringify(logContents), level: type });
// Logger.log({ message: 'client->server', level: type, logContents });
};
export default logClient;

View File

@ -25,7 +25,7 @@ class ServerLoggerStream extends ServerStream {
this.rec = rec;
if (fullInfo.meetingId != null) {
this.rec.clientInfo = fullInfo;
this.rec.userInfo = fullInfo;
}
this.rec.clientBuild = Meteor.settings.public.app.html5ClientBuild;
return super.write(this.rec);
@ -39,7 +39,14 @@ class MeteorStream {
this.rec = rec;
if (fullInfo.meetingId != null) {
Meteor.call('logClient', nameFromLevel[this.rec.level], this.rec.msg, fullInfo);
Meteor.call(
'logClient',
nameFromLevel[this.rec.level],
this.rec.msg,
this.rec.logCode,
this.rec.extraInfo || {},
fullInfo,
);
} else {
Meteor.call('logClient', nameFromLevel[this.rec.level], this.rec.msg);
}

View File

@ -72,7 +72,12 @@ const DesktopShare = ({
notify(intl.formatMessage(intlMessages.iceConnectionStateError), 'error', 'desktop');
break;
default:
logger.error({ logCode: 'desktopshare_default_error' }, error || 'Default error handler');
logger.error({
logCode: 'desktopshare_default_error',
extraInfo: {
maybeError: error || 'Default error handler',
},
}, 'Default error handler for screenshare');
}
screenShareEndAlert();
};

View File

@ -3,8 +3,8 @@ import _ from 'lodash';
import PropTypes from 'prop-types';
import cx from 'classnames';
import logger from '/imports/startup/client/logger';
import { styles } from '../audio-modal/styles';
import browser from 'browser-detect';
import { styles } from '../audio-modal/styles';
const propTypes = {
kind: PropTypes.oneOf(['audioinput', 'audiooutput', 'videoinput']),
@ -33,13 +33,20 @@ class DeviceSelector extends Component {
}
componentDidMount() {
const { kind } = this.props;
const handleEnumerateDevicesSuccess = (deviceInfos) => {
const devices = deviceInfos.filter(d => d.kind === this.props.kind);
logger.info({ logCode: 'audiodeviceselector_component_enumeratedevices_success' }, `Success on enumerateDevices() for ${this.props.kind}: ${JSON.stringify(devices)}`);
const devices = deviceInfos.filter(d => d.kind === kind);
logger.info({
logCode: 'audiodeviceselector_component_enumeratedevices_success',
extraInfo: {
deviceKind: kind,
devices,
},
}, 'Success on enumerateDevices() for audio');
this.setState({
devices,
options: devices.map((d, i) => ({
label: d.label || `${this.props.kind} - ${i}`,
label: d.label || `${kind} - ${i}`,
value: d.deviceId,
key: _.uniqueId('device-option-'),
})),
@ -50,15 +57,20 @@ class DeviceSelector extends Component {
.enumerateDevices()
.then(handleEnumerateDevicesSuccess)
.catch((err) => {
logger.error({ logCode: 'audiodeviceselector_component_enumeratedevices_error' }, `Error on enumerateDevices(): ${JSON.stringify(err)}`);
logger.error({
logCode: 'audiodeviceselector_component_enumeratedevices_error',
extraInfo: {
deviceKind: kind,
},
}, 'Error on enumerateDevices(): ');
});
}
handleSelectChange(event) {
const { value } = event.target;
const { onChange } = this.props;
const { onChange, devices } = this.props;
this.setState({ value }, () => {
const selectedDevice = this.state.devices.find(d => d.deviceId === value);
const selectedDevice = devices.find(d => d.deviceId === value);
onChange(selectedDevice.deviceId, selectedDevice, event);
});
}
@ -79,20 +91,19 @@ class DeviceSelector extends Component {
className={cx(styles.select, className)}
>
{
options.length ?
options.map(option => (
options.length
? options.map(option => (
<option
key={option.key}
value={option.value}
>
{option.label}
</option>
)) :
(
(kind == 'audiooutput' && browser().name == 'safari') ?
<option value="not-found">Default</option>
:
<option value="not-found">{`no ${kind} found`}</option>
))
: (
(kind == 'audiooutput' && browser().name == 'safari')
? <option value="not-found">Default</option>
: <option value="not-found">{`no ${kind} found`}</option>
)
}
</select>

View File

@ -157,7 +157,10 @@ class Pad extends PureComponent {
};
this.recognition.onerror = (event) => {
logger.error({ logCode: 'captions_recognition' }, event.error);
logger.error({
logCode: 'captions_recognition',
extraInfo: { error: event.error },
}, 'Captions pad error on recognition');
};
}
}

View File

@ -135,12 +135,22 @@ class VideoPlayer extends Component {
if (data.rate !== this.player.getPlaybackRate()) {
this.player.setPlaybackRate(data.rate);
logger.debug({ logCode: 'external_video_client_update_rate' }, 'Change external video playback rate to:', data.rate);
logger.debug({
logCode: 'external_video_client_update_rate',
extraInfo: {
newRate: data.rate,
},
}, 'Change external video playback rate.');
}
if (Math.abs(this.player.getCurrentTime() - data.time) > SYNC_INTERVAL_SECONDS) {
this.player.seekTo(data.time, true);
logger.debug({ logCode: 'external_video_client_update_seek' }, 'Seek external video to:', data.time);
logger.debug({
logCode: 'external_video_client_update_seek',
extraInfo: {
time: data.time,
},
}, 'Seek external video to:');
}
if (this.playerState !== data.state) {

View File

@ -66,7 +66,11 @@ class JoinHandler extends Component {
location: window.location.href,
};
logger.info({ logCode: 'joinhandler_component_clientinfo' }, clientInfo);
logger.info({
logCode: 'joinhandler_component_clientinfo',
extraInfo: { clientInfo },
},
'Log informatin about the client');
};
const setAuth = (resp) => {
@ -135,11 +139,22 @@ class JoinHandler extends Component {
Session.set('openPanel', '');
}
logger.info({ logCode: 'joinhandler_component_joinroutehandler_success' }, `User successfully went through main.joinRouteHandler with [${JSON.stringify(response)}].`);
logger.info({
logCode: 'joinhandler_component_joinroutehandler_success',
extraInfo: {
response,
},
}, 'User successfully went through main.joinRouteHandler');
} else {
const e = new Error(response.message);
if (!Session.get('codeError')) Session.set('errorMessageDescription', response.message);
logger.error({ logCode: 'joinhandler_component_joinroutehandler_error' }, `User faced [${e}] on main.joinRouteHandler. Error was:`, JSON.stringify(response));
logger.error({
logCode: 'joinhandler_component_joinroutehandler_error',
extraInfo: {
response,
error: e,
},
}, 'User faced an error on main.joinRouteHandler.');
}
this.changeToJoin(true);
}

View File

@ -142,7 +142,7 @@ class MeetingEnded extends React.PureComponent {
};
// client logger
logger.info({ feedback: message, logCode: 'feedback' }, 'Feedback');
logger.info({ logCode: 'feedback_functionality', extraInfo: { feedback: message } }, 'Feedback component');
const FEEDBACK_WAIT_TIME = 500;
setTimeout(() => {
@ -164,7 +164,7 @@ class MeetingEnded extends React.PureComponent {
const noRating = selected <= 0;
logger.info({ endedCode: code, logCode: 'meeting_ended_code' }, code);
logger.info({ logCode: 'meeting_ended_code', extraInfo: { endedCode: code } }, 'Meeting ended component');
return (
<div className={styles.parent}>

View File

@ -294,7 +294,10 @@ class PresentationUploader extends Component {
})
.catch((error) => {
notify(intl.formatMessage(intlMessages.genericError), 'error');
logger.error({ logCode: 'presentationuploader_component_save_error' }, error);
logger.error({
logCode: 'presentationuploader_component_save_error',
extraInfo: { error },
}, 'Presentation uploader catch error on confirm');
this.setState({
disableActions: false,

View File

@ -43,7 +43,10 @@ export default withTracker(() => {
}
const subscriptionErrorHandler = {
onError: (error) => {
logger.error({ logCode: 'startup_client_subscription_error' }, error);
logger.error({
logCode: 'startup_client_subscription_error',
extraInfo: { error },
}, 'Error while subscribing to collections');
Session.set('codeError', error.error);
},
};

View File

@ -220,7 +220,13 @@ class VideoPreview extends Component {
if (!this._isMounted) return;
// webcam might no longer exist or be available
logger.debug(`Error with profile: ${CAMERA_PROFILES[currNum].name}`);
logger.debug({
logCode: 'video_preview_check_webcam',
extraInfo: {
camProfile: CAMERA_PROFILES[currNum],
currNum,
},
}, 'Error with camera profile');
this.handleGUMError(error);
@ -234,13 +240,27 @@ class VideoPreview extends Component {
this.doGUM(deviceId, CAMERA_PROFILES[currNum]).then((stream) => {
if (!this._isMounted) return;
logger.debug(`Display preview came back for profile: ${CAMERA_PROFILES[currNum].name}`);
logger.debug({
logCode: 'video_preview_next_profile',
extraInfo: {
camProfile: CAMERA_PROFILES[currNum],
currNum,
},
}, 'Display preview came back');
this.video.srcObject = stream;
this.deviceStream = stream;
}).catch((error) => {
if (!this._isMounted) return;
logger.debug(`Error with fetching profile {${CAMERA_PROFILES[currNum].name}} skipping to next profile. Error is {${error.name}}`);
logger.debug({
logCode: 'video_preview_next_profile',
extraInfo: {
camProfile: CAMERA_PROFILES[currNum],
currNum,
error,
},
}, 'Error with fetching profile, skipping to next');
currNum++;
nextProfile();
});
@ -260,10 +280,22 @@ class VideoPreview extends Component {
if (this.video.videoWidth !== previousWidth || this.video.videoHeight !== previousHeight) {
previousWidth = this.video.videoWidth;
previousHeight = this.video.videoHeight;
logger.debug(`Found profile ${CAMERA_PROFILES[currNum].name}`);
logger.debug({
logCode: 'video_preview_found_profile',
extraInfo: {
camProfile: CAMERA_PROFILES[currNum],
currNum,
},
}, 'Found profile');
availableProfiles.push(CAMERA_PROFILES[currNum]);
} else {
logger.debug(`Not including profile ${CAMERA_PROFILES[currNum].name}`);
logger.debug({
logCode: 'video_preview_not_including_profile',
extraInfo: {
camProfile: CAMERA_PROFILES[currNum],
currNum,
},
}, 'Not including profile');
}
currNum++;
@ -276,7 +308,12 @@ class VideoPreview extends Component {
if (availableProfiles.length > 0) {
const defaultProfile = availableProfiles.find(profile => profile.default)
|| availableProfiles[0];
logger.debug(`Found default profile: ${JSON.stringify(defaultProfile)}`);
logger.debug({
logCode: 'video_preview_found_default_profile',
extraInfo: {
defaultProfile,
},
}, 'Found default profile');
this.displayPreview(deviceId, defaultProfile);
}
@ -321,8 +358,12 @@ class VideoPreview extends Component {
this.video.srcObject = stream;
this.deviceStream = stream;
}).catch((error) => {
logger.warning({ logCode: 'video_preview_error' }, `Error displaying final selection. name: [${error.name}] message: [${error.message}]`);
// logger.debug(error);
logger.warn({
logCode: 'video_preview_do_gum_preview_error',
extraInfo: {
error,
},
}, 'Error displaying final selection.');
});
}
@ -353,7 +394,14 @@ class VideoPreview extends Component {
}
});
logger.debug(`Enumerate devices came back. There are ${devices.length} devices and ${webcams.length} are video inputs`);
logger.debug({
logCode: 'video_preview_enumerate_devices',
extraInfo: {
devices,
webcams,
},
}, `Enumerate devices came back. There are ${devices.length} devices and ${webcams.length} are video inputs`);
if (initialDeviceId) {
this.setState({
@ -364,13 +412,23 @@ class VideoPreview extends Component {
}
}).catch((error) => {
// CHANGE THIS TO SOMETHING USEFUL
logger.warning(`Error enumerating devices. name: [${error.name}] message: [${error.message}]`);
logger.warn({
logCode: 'video_preview_enumerate_error',
extraInfo: {
error,
},
}, 'Error enumerating devices');
this.handleGUMError(error);
});
});
} catch (error) {
// CHANGE THIS TO SOMETHING USEFUL
logger.warning(`Error grabbing initial video stream. name: [${error.name}] message: [${error.message}]`);
logger.warn({
logCode: 'video_preview_grabbing_error',
extraInfo: {
error,
},
}, 'Error grabbing initial video stream');
this.handleGUMError(error);
}
}

View File

@ -281,7 +281,10 @@ class VideoProvider extends Component {
}
onWsClose() {
this.logger('debug', '------ Websocket connection closed.', 'video_provider_onwsclose', { topic: 'ws' });
logger.debug({
logCode: 'video_provider_onwsclose',
extraInfo: { topic: 'ws' },
}, '------ Websocket connection closed.');
clearInterval(this.pingInterval);
@ -293,7 +296,10 @@ class VideoProvider extends Component {
}
onWsOpen() {
this.logger('debug', '------ Websocket connection opened.', 'video_provider_onwsopen', { topic: 'ws' });
logger.debug({
logCode: 'video_provider_onwsopen',
extraInfo: { topic: 'ws' },
}, '------ Websocket connection opened.');
// -- Resend queued messages that happened when socket was not connected
while (this.wsQueue.length > 0) {
@ -333,14 +339,6 @@ class VideoProvider extends Component {
}
}
logger(type, message, logCode, options = {}) {
const { userId, userName } = this.props;
const topic = options.topic || 'video';
logger[type](`${JSON.stringify(Object.assign(options, {
userId, userName, topic, logCode,
}))}, [${topic}] ${message}`);
}
_sendPauseStream(id, role, state) {
this.sendMessage({
cameraId: id,
@ -353,10 +351,15 @@ class VideoProvider extends Component {
pauseViewers() {
const { userId } = this.props;
this.logger('debug', 'Calling pause in viewer streams', 'video_provider_pause_viewers');
logger.debug({
logCode: 'video_provider_pause_viewers',
extraInfo: {
topic: 'video',
},
}, 'Calling pause in viewer streams');
Object.keys(this.webRtcPeers).forEach((id) => {
if (userId !== id && this.webRtcPeers[id].started) {
if (userId !== id && this.webRtcPeers[id] && this.webRtcPeers[id].started) {
this._sendPauseStream(id, 'viewer', true);
}
});
@ -364,10 +367,15 @@ class VideoProvider extends Component {
unpauseViewers() {
const { userId } = this.props;
this.logger('debug', 'Calling un-pause in viewer streams', 'video_provider_unpause_viewers');
logger.debug({
logCode: 'video_provider_unpause_viewers',
extraInfo: {
topic: 'video',
},
}, 'Calling un-pause in viewer streams');
Object.keys(this.webRtcPeers).forEach((id) => {
if (id !== userId && this.webRtcPeers[id].started) {
if (id !== userId && this.webRtcPeers[id] && this.webRtcPeers[id].started) {
this._sendPauseStream(id, 'viewer', false);
}
});
@ -387,7 +395,14 @@ class VideoProvider extends Component {
const jsonMessage = JSON.stringify(message);
ws.send(jsonMessage, (error) => {
if (error) {
this.logger('error', `client: Websocket error '${error}' on message '${message.id}'`, 'video_provider_ws_error', { topic: 'ws' });
logger.error({
logCode: 'video_provider_ws_error',
extraInfo: {
topic: 'ws',
error,
message,
},
}, 'client: Websocket error');
}
});
} else if (message.id !== 'stop') {
@ -404,13 +419,26 @@ class VideoProvider extends Component {
const id = message.cameraId;
const peer = this.webRtcPeers[id];
this.logger('debug', 'SDP answer received from server. Processing ...', 'video_provider_sdp_received',
{ cameraId: id, sdpAnswer: message.sdpAnswer });
logger.debug({
logCode: 'video_provider_sdp_received',
extraInfo: {
topic: 'video',
cameraId: id,
sdpAnswer: message.sdpAnswer,
},
}, 'SDP answer received from server. Processing ...');
if (peer) {
peer.processAnswer(message.sdpAnswer, (error) => {
if (error) {
return this.logger('debug', JSON.stringify(error), 'video_provider_peer_process_answer', { cameraId: id });
return logger.debug({
logCode: 'video_provider_peer_process_answer',
extraInfo: {
topic: 'video',
error,
cameraId: id,
},
}, 'Processing answer...');
}
peer.didSDPAnswered = true;
@ -418,20 +446,38 @@ class VideoProvider extends Component {
return true;
});
} else {
this.logger('warn', '[startResponse] Message arrived after the peer was already thrown out, discarding it...', 'video_provider_no_peer');
logger.warn({
logCode: 'video_provider_no_peer',
extraInfo: {
topic: 'video',
},
}, '[startResponse] Message arrived after the peer was already thrown out, discarding it...');
}
}
handleIceCandidate(message) {
const webRtcPeer = this.webRtcPeers[message.cameraId];
this.logger('debug', 'Received remote ice candidate', 'video_provider_ice_candidate_received', { topic: 'ice', candidate: message.candidate });
logger.debug({
logCode: 'video_provider_ice_candidate_received',
extraInfo: {
topic: 'ice',
candidate: message.candidate,
},
}, 'Received remote ice candidate');
if (webRtcPeer) {
if (webRtcPeer.didSDPAnswered) {
webRtcPeer.addIceCandidate(message.candidate, (err) => {
if (err) {
return this.logger('error', `Error adding candidate: ${err}`, 'video_provider_ice_candidate_cant_add', { cameraId: message.cameraId });
return logger.error({
logCode: 'video_provider_ice_candidate_cant_add',
extraInfo: {
topic: 'ice',
error: err,
cameraId: message.cameraId,
},
}, 'Error adding candidate');
}
return true;
});
@ -442,12 +488,25 @@ class VideoProvider extends Component {
webRtcPeer.iceQueue.push(message.candidate);
}
} else {
this.logger('warn', ' [iceCandidate] Message arrived after the peer was already thrown out, discarding it...', 'video_provider_ice_candidate_arrived_late', { cameraId: message.cameraId });
logger.warn({
logCode: 'video_provider_ice_candidate_arrived_late',
extraInfo: {
topic: 'ice',
cameraId: message.cameraId,
},
}, 'Message arrived after the peer was already thrown out, discarding it...');
}
}
stopWebRTCPeer(id, restarting = false) {
this.logger('info', 'Stopping webcam', 'video_provider_stopping_webcam', { cameraId: id });
logger.info({
logCode: 'video_provider_stopping_webcam',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, 'Stopping webcam');
const { userId } = this.props;
const shareWebcam = id === userId;
@ -485,7 +544,13 @@ class VideoProvider extends Component {
destroyWebRTCPeer(id) {
const webRtcPeer = this.webRtcPeers[id];
if (webRtcPeer) {
this.logger('info', 'Stopping WebRTC peer', 'video_provider_destroy_webrtc_peers', { cameraId: id });
logger.info({
logCode: 'video_provider_destroy_webrtc_peers',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, 'Stopping WebRTC peer');
if (typeof webRtcPeer.dispose === 'function') {
webRtcPeer.dispose();
}
@ -495,7 +560,13 @@ class VideoProvider extends Component {
updateCurrentWebcamsConnection(this.webRtcPeers);
}
} else {
this.logger('warn', 'No WebRTC peer to stop (not an error)', 'video_provider_no_peer_to_destroy', { cameraId: id });
logger.warn({
logCode: 'video_provider_no_peer_to_destroy',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, 'No WebRTC peer to stop (not an error)');
}
}
@ -513,7 +584,13 @@ class VideoProvider extends Component {
try {
iceServers = await fetchWebRTCMappedStunTurnServers(sessionToken);
} catch (error) {
this.logger('error', 'Video provider failed to fetch ice servers, using default', 'video_provider_missing_ice_servers');
logger.error({
logCode: 'video_provider_missing_ice_servers',
extraInfo: {
topic: 'video',
error,
},
}, 'Video provider failed to fetch ice servers, using default');
} finally {
const profileId = Session.get('WebcamProfileId') || '';
const cameraProfile = CAMERA_PROFILES.find(profile => profile.id === profileId)
@ -563,7 +640,14 @@ class VideoProvider extends Component {
return this._webRTCOnError(errorGenOffer, id, shareWebcam);
}
this.logger('debug', `Invoking SDP offer callback function ${window.location.host}`, 'video_provider_sdp_offer_callback', { cameraId: id, offerSdp });
logger.debug({
logCode: 'video_provider_sdp_offer_callback',
extraInfo: {
topic: 'video',
cameraId: id,
offerSdp,
},
}, `Invoking SDP offer callback function ${window.location.host}`);
const message = {
type: 'video',
@ -596,7 +680,13 @@ class VideoProvider extends Component {
const { intl, userId } = this.props;
return () => {
this.logger('error', `Camera share has not succeeded in ${CAMERA_SHARE_FAILED_WAIT_TIME}`, 'video_provider_cam_timeout', { cameraId: id });
logger.error({
logCode: 'video_provider_cam_timeout',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, `Camera share has not succeeded in ${CAMERA_SHARE_FAILED_WAIT_TIME}`);
if (userId === id) {
VideoProvider.notifyError(intl.formatMessage(intlClientErrors.mediaFlowTimeout));
@ -612,7 +702,14 @@ class VideoProvider extends Component {
this.restartTimer[id] = Math
.min(2 * this.restartTimer[id], MAX_CAMERA_SHARE_FAILED_WAIT_TIME);
this.logger('info', `Reconnecting peer ${id} with timer`, 'video_provider_reconnecting_peer', this.restartTimer);
logger.info({
logCode: 'video_provider_reconnecting_peer',
extraInfo: {
topic: 'video',
restartTimer: this.restartTimer,
peerId: id,
},
}, `Reconnecting peer ${id} with timer`);
}
};
}
@ -625,7 +722,14 @@ class VideoProvider extends Component {
peer.addIceCandidate(candidate, (err) => {
if (err) {
VideoProvider.notifyError(intl.formatMessage(intlClientErrors.iceCandidateError));
return this.logger('error', `Error adding candidate: ${err}`, 'video_provider_cant_add_candidate', { cameraId });
return logger.error({
logCode: 'video_provider_cant_add_candidate',
extraInfo: {
topic: 'ice',
err,
cameraId,
},
}, 'Error adding candidate.');
}
return true;
});
@ -643,13 +747,28 @@ class VideoProvider extends Component {
return;
}
this.logger('error', ' WebRTC peerObj create error', 'video_provider_webrtc_error_before', { id, error });
logger.error({
logCode: 'video_provider_webrtc_error_before',
extraInfo: {
topic: 'ice',
error,
id,
},
}, 'WebRTC peerObj create error');
const errorMessage = intlClientErrors[error.name]
|| intlSFUErrors[error] || intlClientErrors.permissionError;
VideoProvider.notifyError(intl.formatMessage(errorMessage));
this.stopWebRTCPeer(id);
this.logger('error', errorMessage, 'video_provider_webrtc_error_after', { cameraId: id, errorMessage });
logger.error({
logCode: 'video_provider_webrtc_error_after',
extraInfo: {
topic: 'video',
cameraId: id,
errorMessage,
},
}, '_webRTCOnError');
}
_getOnIceCandidateCallback(id, shareWebcam) {
@ -665,12 +784,25 @@ class VideoProvider extends Component {
if (shouldSetReconnectionTimeout) {
this.restartTimer[id] = this.restartTimer[id] || CAMERA_SHARE_FAILED_WAIT_TIME;
this.logger('debug', `Setting a camera connection restart in ${this.restartTimer[id]}`, 'video_provider_cam_restart', { cameraId: id });
logger.debug({
logCode: 'video_provider_cam_restart',
extraInfo: {
topic: 'video',
cameraId: id,
time: this.restartTimer[id],
},
}, `Setting a camera connection restart in ${this.restartTimer[id]}`);
this.restartTimeout[id] = setTimeout(this._getWebRTCStartTimeout(id, shareWebcam),
this.restartTimer[id]);
}
this.logger('debug', 'Generated local ice candidate', 'video_provider_generated_local_ice', { topic: 'ice', candidate });
logger.debug({
logCode: 'video_provider_generated_local_ice',
extraInfo: {
topic: 'ice',
candidate,
},
}, 'Generated local ice candidate');
const message = {
type: 'video',
@ -693,7 +825,14 @@ class VideoProvider extends Component {
// prevent the same error from being detected multiple times
peer.peerConnection.oniceconnectionstatechange = null;
this.logger('error', `ICE connection state id:${id}, connectionState:${connectionState}`, 'video_provider_ice_connection_failed_state');
logger.error({
logCode: 'video_provider_ice_connection_failed_state',
extraInfo: {
topic: 'ice',
id,
connectionState,
},
}, 'ICE connection state change');
this.stopWebRTCPeer(id);
VideoProvider.notifyError(intl.formatMessage(intlClientErrors.iceConnectionStateError));
@ -705,7 +844,14 @@ class VideoProvider extends Component {
const { userId } = this.props;
const video = this.videoTags[id];
if (video == null) {
this.logger('warn', `Peer ${id} ${userId} has not been started yet`, 'video_provider_attach_video_stream');
logger.warn({
logCode: 'video_provider_attach_video_stream',
extraInfo: {
topic: 'video',
id,
userId,
},
}, `Peer ${id} ${userId} has not been started yet`);
return;
}
@ -879,14 +1025,27 @@ class VideoProvider extends Component {
callback(result);
}, (exception) => {
this.logger('error', `customGetStats() Promise rejected: ${exception.message}`, 'video_provider_get_stats_exception');
logger.error({
logCode: 'video_provider_get_stats_exception',
extraInfo: {
topic: 'video',
exception,
},
}, 'customGetStats() Promise rejected');
callback(null);
});
}
monitorTrackStart(peer, track, local, callback) {
const that = this;
this.logger('info', 'Starting stats monitoring on', 'video_provider_monitor_track_start', { cameraId: track.id });
logger.info({
logCode: 'video_provider_monitor_track_start',
extraInfo: {
topic: 'video',
cameraId: track.id,
},
}, 'Starting stats monitoring.');
const getStatsInterval = 2000;
const callGetStats = () => {
@ -911,7 +1070,12 @@ class VideoProvider extends Component {
getStatsInterval,
);
} else {
this.logger('info', 'Already monitoring this track', 'video_provider_already_monitoring_track');
logger.info({
logCode: 'video_provider_already_monitoring_track',
extraInfo: {
topic: 'video',
},
}, 'Already monitoring this track');
}
}
@ -919,9 +1083,21 @@ class VideoProvider extends Component {
if (this.monitoredTracks[trackId]) {
clearInterval(this.monitoredTracks[trackId]);
delete this.monitoredTracks[trackId];
this.logger('debug', `Track ${trackId} removed`, 'video_provider_stop_monitoring');
logger.debug({
logCode: 'video_provider_stop_monitoring',
extraInfo: {
topic: 'video',
trackId,
},
}, `Track ${trackId} removed`);
} else {
this.logger('debug', `Track ${trackId} is not monitored`, 'video_provider_already_stopped_monitoring');
logger.debug({
logCode: 'video_provider_already_stopped_monitoring',
extraInfo: {
topic: 'video',
trackId,
},
}, `Track ${trackId} is not monitored`);
}
}
@ -943,7 +1119,13 @@ class VideoProvider extends Component {
handlePlayStop(message) {
const { cameraId } = message;
this.logger('info', 'Handle play stop for camera', 'video_provider_handle_play_stop', { cameraId });
logger.info({
logCode: 'video_provider_handle_play_stop',
extraInfo: {
topic: 'video',
cameraId,
},
}, 'Handle play stop for camera');
this.stopWebRTCPeer(cameraId);
}
@ -953,7 +1135,13 @@ class VideoProvider extends Component {
if (peer) {
const { userId } = this.props;
this.logger('info', 'Handle play start for camera', 'video_provider_handle_play_start', { cameraId: id });
logger.info({
logCode: 'video_provider_handle_play_start',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, 'Handle play start for camera');
peer.started = true;
@ -971,7 +1159,13 @@ class VideoProvider extends Component {
VideoService.joinedVideo();
}
} else {
this.logger('warn', '[playStart] Message arrived after the peer was already thrown out, discarding it...', 'video_provider_play_start_discarding');
logger.warn({
logCode: 'video_provider_play_start_discarding',
extraInfo: {
topic: 'video',
cameraId: id,
},
}, '[playStart] Message arrived after the peer was already thrown out, discarding it...');
}
}
@ -979,9 +1173,17 @@ class VideoProvider extends Component {
const { intl } = this.props;
const { userId } = this.props;
const { code, reason } = message;
this.logger('error', 'Received error from SFU:', 'video_provider_sfu_error', {
code, reason, streamId: message.streamId, userId,
});
logger.error({
logCode: 'video_provider_sfu_error',
extraInfo: {
topic: 'video',
code,
reason,
streamId: message.streamId,
userId,
},
}, 'Received error from SFU');
if (message.streamId === userId) {
this.unshareWebcam();
VideoProvider.notifyError(intl.formatMessage(intlSFUErrors[code]
@ -990,12 +1192,23 @@ class VideoProvider extends Component {
this.stopWebRTCPeer(message.cameraId);
}
this.logger('error', `Handle error ---------------------> ${message.message}`, 'video_provider_handle_sfu_error', { message });
logger.error({
logCode: 'video_provider_handle_sfu_error',
extraInfo: {
topic: 'video',
message,
},
}, 'Handle error');
}
shareWebcam() {
if (this.connectedToMediaServer()) {
this.logger('info', 'Sharing webcam', 'video_provider_share_webcam');
logger.info({
logCode: 'video_provider_share_webcam',
extraInfo: {
topic: 'video',
},
}, 'Sharing webcam');
this.sharedWebcam = true;
VideoService.joiningVideo();
}
@ -1003,7 +1216,12 @@ class VideoProvider extends Component {
unshareWebcam() {
const { userId } = this.props;
this.logger('info', 'Unsharing webcam', 'video_provider_unshare_webcam');
logger.info({
logCode: 'video_provider_unshare_webcam',
extraInfo: {
topic: 'video',
},
}, 'Unsharing webcam');
VideoService.sendUserUnshareWebcam(userId);
VideoService.exitedVideo();

View File

@ -53,10 +53,10 @@ class VideoListItem extends Component {
if (p && (typeof Promise !== 'undefined') && (p instanceof Promise)) {
// Catch exception when playing video
p.catch((e) => {
logger.warn(
{ logCode: 'videolistitem_component_play_error' },
`Could not play video: ${JSON.stringify(e)}`,
);
logger.warn({
logCode: 'videolistitem_component_play_error',
extraInfo: { error: e },
}, 'Could not play video');
});
}
}

View File

@ -43,8 +43,8 @@ function handleAddedAnnotation({
Annotations.update(fakeAnnotation._id, {
$set: {
position: annotation.position,
'annotationInfo.color': isEqual(fakePoints, lastPoints) || annotation.status === DRAW_END ?
annotation.annotationInfo.color : fakeAnnotation.annotationInfo.color,
'annotationInfo.color': isEqual(fakePoints, lastPoints) || annotation.status === DRAW_END
? annotation.annotationInfo.color : fakeAnnotation.annotationInfo.color,
},
$inc: { version: 1 }, // TODO: Remove all this version stuff
});
@ -54,7 +54,10 @@ function handleAddedAnnotation({
Annotations.upsert(query.selector, query.modifier, (err) => {
if (err) {
logger.error({ logCode: 'whiteboard_annotation_upsert_error' }, err);
logger.error({
logCode: 'whiteboard_annotation_upsert_error',
extraInfo: { error: err },
}, 'Error on adding an annotation');
return;
}
@ -117,9 +120,9 @@ function increaseBrightness(realHex, percent) {
const b = parseInt(hex.substr(4, 2), 16);
/* eslint-disable no-bitwise, no-mixed-operators */
return parseInt(((0 | (1 << 8) + r + ((256 - r) * percent) / 100).toString(16)).substr(1) +
((0 | (1 << 8) + g + ((256 - g) * percent) / 100).toString(16)).substr(1) +
((0 | (1 << 8) + b + ((256 - b) * percent) / 100).toString(16)).substr(1), 16);
return parseInt(((0 | (1 << 8) + r + ((256 - r) * percent) / 100).toString(16)).substr(1)
+ ((0 | (1 << 8) + g + ((256 - g) * percent) / 100).toString(16)).substr(1)
+ ((0 | (1 << 8) + b + ((256 - b) * percent) / 100).toString(16)).substr(1), 16);
/* eslint-enable no-bitwise, no-mixed-operators */
}
@ -144,11 +147,10 @@ const proccessAnnotationsQueue = async () => {
const annotations = annotationsQueue.splice(0, queueSize);
// console.log('annotationQueue.length', annotationsQueue, annotationsQueue.length);
await makeCall('sendBulkAnnotations', annotations.filter(({ id }) => !discardedList.includes(id)))
await makeCall('sendBulkAnnotations', annotations.filter(({ id }) => !discardedList.includes(id)));
// ask tiago
const delayPerc =
Math.min(annotationsMaxDelayQueueSize, queueSize) / annotationsMaxDelayQueueSize;
const delayPerc = Math.min(annotationsMaxDelayQueueSize, queueSize) / annotationsMaxDelayQueueSize;
const delayDelta = annotationsBufferTimeMax - annotationsBufferTimeMin;
const delayTime = annotationsBufferTimeMin + (delayDelta * delayPerc);
setTimeout(proccessAnnotationsQueue, delayTime);

View File

@ -184,7 +184,13 @@ class AudioManager {
clearTimeout(iceGatheringTimeout);
}
logger.error({ logCode: 'audiomanager_listenonly_error' }, `Listen only error:${JSON.stringify(err)} on try ${retries}`);
logger.error({
logCode: 'audiomanager_listenonly_error',
extraInfo: {
error: err,
retries,
},
}, 'Listen only error');
throw {
type: 'MEDIA_ERROR',
message: this.messages.error.MEDIA_ERROR,
@ -331,7 +337,13 @@ class AudioManager {
const errorKey = this.messages.error[error] || this.messages.error.GENERIC_ERROR;
const errorMsg = this.intl.formatMessage(errorKey, { 0: bridgeError });
this.error = !!error;
logger.error({ logCode: 'audio_failure', error, cause: bridgeError }, `Audio Error ${JSON.stringify(errorMsg)}`);
logger.error({
logCode: 'audio_failure',
extraInfo: {
error,
cause: bridgeError,
},
}, 'Audio Error');
if (silenceNotifications !== true) {
this.notify(errorMsg, true);
this.exitAudio();
@ -362,7 +374,10 @@ class AudioManager {
audio.src = 'resources/sounds/silence.mp3';
audio.play().catch((e) => {
logger.warn({ logCode: 'audiomanager_error_test_audio' }, 'Error on playing test audio:', e);
logger.warn({
logCode: 'audiomanager_error_test_audio',
extraInfo: { error: e },
}, 'Error on playing test audio');
});
return dest.stream;

View File

@ -135,6 +135,7 @@ class Auth {
fullname: this.fullname,
confname: this.confname,
externUserID: this.externUserID,
uniqueClientSession: this.uniqueClientSession,
};
}
@ -168,6 +169,7 @@ class Auth {
this.fullname = null;
this.externUserID = null;
this.confname = null;
this.uniqueClientSession = null;
return Promise.resolve(...args);
}
@ -193,7 +195,10 @@ class Auth {
this.loggedIn = false;
return this.validateAuthToken()
.then(() => { this.loggedIn = true; });
.then(() => {
this.loggedIn = true;
this.uniqueClientSession = Math.random().toString(36).substring(6);
});
}
validateAuthToken() {

View File

@ -150,7 +150,12 @@ export const startBandwidthMonitoring = () => {
if (lastEffectiveConnectionType
&& lastEffectiveConnectionType.effectiveConnectionType !== effectiveType) {
logger.info({ logCode: 'user_connection_instability' }, `User ${Auth.userID} effective connection is now ${effectiveType}`);
logger.info({
logCode: 'user_connection_instability',
extraInfo: {
effectiveType,
},
}, `User ${Auth.userID} effective connection is now ${effectiveType}`);
makeCall('setUserEffectiveConnectionType', effectiveType);
}
}, 5000);