Skip to content

Commit

Permalink
Fix mercury log (#3236)
Browse files Browse the repository at this point in the history
  • Loading branch information
@maxinteger
maxinteger authored Jan 2, 2024
1 parent 82cb2ce commit f209d78
Show file tree
Hide file tree
Showing 4 changed files with 93 additions and 63 deletions.
70 changes: 38 additions & 32 deletions packages/@webex/internal-plugin-mercury/src/mercury.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ const Mercury = WebexPlugin.extend({
@oneFlight
connect(webSocketUrl) {
if (this.connected) {
this.logger.info('mercury: already connected, will not connect again');
this.logger.info(`${this.namespace}: already connected, will not connect again`);

return Promise.resolve();
}
Expand All @@ -59,7 +59,7 @@ const Mercury = WebexPlugin.extend({
return Promise.resolve(
this.webex.internal.device.registered || this.webex.internal.device.register()
).then(() => {
this.logger.info('mercury: connecting');
this.logger.info(`${this.namespace}: connecting`);

return this._connectWithBackoff(webSocketUrl);
});
Expand All @@ -69,16 +69,14 @@ const Mercury = WebexPlugin.extend({
disconnect() {
return new Promise((resolve) => {
if (this.backoffCall) {
this.logger.info('mercury: aborting connection');
this.logger.info(`${this.namespace}: aborting connection`);
this.backoffCall.abort();
}

if (this.socket) {
this.socket.removeAllListeners('message');
this.once('offline', resolve);
this.socket.close();

return;
resolve(this.socket.close());
}

resolve();
Expand Down Expand Up @@ -165,7 +163,7 @@ const Mercury = WebexPlugin.extend({
Promise.all([this._prepareUrl(socketUrl), this.webex.credentials.getUserToken()])
.then(([webSocketUrl, token]) => {
if (!this.backoffCall) {
const msg = 'mercury: prevent socket open when backoffCall no longer defined';
const msg = `${this.namespace}: prevent socket open when backoffCall no longer defined`;

this.logger.info(msg);

Expand All @@ -185,14 +183,16 @@ const Mercury = WebexPlugin.extend({

// if the consumer has supplied request options use them
if (this.webex.config.defaultMercuryOptions) {
this.logger.info('mercury: setting custom options');
this.logger.info(`${this.namespace}: setting custom options`);
options = {...options, ...this.webex.config.defaultMercuryOptions};
}

// Set the socket before opening it. This allows a disconnect() to close
// the socket if it is in the process of being opened.
this.socket = socket;

this.logger.info(`${this.namespace} connection url: ${webSocketUrl}`);

return socket.open(webSocketUrl, options);
})
.then(() => {
Expand All @@ -201,6 +201,7 @@ const Mercury = WebexPlugin.extend({
success: true,
},
tags: {
namespace: this.namespace,
action: 'connected',
url: attemptWSUrl,
},
Expand All @@ -225,19 +226,19 @@ const Mercury = WebexPlugin.extend({
if (reason.code !== 1006 && this.backoffCall && this.backoffCall.getNumRetries() > 0) {
this._emit('connection_failed', reason, {retries: this.backoffCall.getNumRetries()});
}
this.logger.info('mercury: connection attempt failed', reason);
this.logger.info(`${this.namespace}: connection attempt failed`, reason);
// UnknownResponse is produced by IE for any 4XXX; treated it like a bad
// web socket url and let WDM handle the token checking
if (reason instanceof UnknownResponse) {
this.logger.info(
'mercury: received unknown response code, refreshing device registration'
`${this.namespace}: received unknown response code, refreshing device registration`
);

return this.webex.internal.device.refresh().then(() => callback(reason));
}
// NotAuthorized implies expired token
if (reason instanceof NotAuthorized) {
this.logger.info('mercury: received authorization error, reauthorizing');
this.logger.info(`${this.namespace}: received authorization error, reauthorizing`);

return this.webex.credentials.refresh({force: true}).then(() => callback(reason));
}
Expand All @@ -250,7 +251,7 @@ const Mercury = WebexPlugin.extend({
// BadRequest implies current credentials are for a Service Account
// Forbidden implies current user is not entitle for Webex
if (reason instanceof BadRequest || reason instanceof Forbidden) {
this.logger.warn('mercury: received unrecoverable response from mercury');
this.logger.warn(`${this.namespace}: received unrecoverable response from mercury`);
this.backoffCall.abort();

return callback(reason);
Expand All @@ -261,13 +262,14 @@ const Mercury = WebexPlugin.extend({
.then((haMessagingEnabled) => {
if (haMessagingEnabled) {
this.logger.info(
'mercury: received a generic connection error, will try to connect to another datacenter'
`${this.namespace}: received a generic connection error, will try to connect to another datacenter`
);
this.webex.internal.metrics.submitClientMetrics('web-ha-mercury', {
fields: {
success: false,
},
tags: {
namespace: this.namespace,
action: 'failed',
error: reason.message,
url: attemptWSUrl,
Expand All @@ -285,7 +287,7 @@ const Mercury = WebexPlugin.extend({
return callback(reason);
})
.catch((reason) => {
this.logger.error('mercury: failed to handle connection failure', reason);
this.logger.error(`${this.namespace}: failed to handle connection failure`, reason);
callback(reason);
});
},
Expand All @@ -301,7 +303,9 @@ const Mercury = WebexPlugin.extend({
this.backoffCall = undefined;
if (err) {
this.logger.info(
`mercury: failed to connect after ${call.getNumRetries()} retries; log statement about next retry was inaccurate; ${err}`
`${
this.namespace
}: failed to connect after ${call.getNumRetries()} retries; log statement about next retry was inaccurate; ${err}`
);

return reject(err);
Expand All @@ -314,7 +318,7 @@ const Mercury = WebexPlugin.extend({

// eslint-disable-next-line prefer-reflect
call = backoff.call((callback) => {
this.logger.info(`mercury: executing connection attempt ${call.getNumRetries()}`);
this.logger.info(`${this.namespace}: executing connection attempt ${call.getNumRetries()}`);
this._attemptConnection(webSocketUrl, callback);
}, onComplete);

Expand All @@ -330,7 +334,7 @@ const Mercury = WebexPlugin.extend({
}

call.on('abort', () => {
this.logger.info('mercury: connection aborted');
this.logger.info(`${this.namespace}: connection aborted`);
reject(new Error('Mercury Connection Aborted'));
});

Expand All @@ -340,16 +344,16 @@ const Mercury = WebexPlugin.extend({
const delay = Math.min(call.strategy_.nextBackoffDelay_, this.config.backoffTimeMax);

this.logger.info(
`mercury: failed to connect; attempting retry ${number + 1} in ${delay} ms`
`${this.namespace}: failed to connect; attempting retry ${number + 1} in ${delay} ms`
);
/* istanbul ignore if */
if (process.env.NODE_ENV === 'development') {
this.logger.debug('mercury: ', err, err.stack);
this.logger.debug(`${this.namespace}: `, err, err.stack);
}

return;
}
this.logger.info('mercury: connected');
this.logger.info(`${this.namespace}: connected`);
});

call.start();
Expand All @@ -362,7 +366,7 @@ const Mercury = WebexPlugin.extend({
try {
this.trigger(...args);
} catch (error) {
this.logger.error('mercury: error occurred in event handler', {
this.logger.error(`${this.namespace}: error occurred in event handler`, {
error,
arguments: args,
});
Expand Down Expand Up @@ -406,52 +410,54 @@ const Mercury = WebexPlugin.extend({
case 1003:
// metric: disconnect
this.logger.info(
`mercury: Mercury service rejected last message; will not reconnect: ${event.reason}`
`${this.namespace}: Mercury service rejected last message; will not reconnect: ${event.reason}`
);
this._emit('offline.permanent', event);
break;
case 4000:
// metric: disconnect
this.logger.info('mercury: socket replaced; will not reconnect');
this.logger.info(`${this.namespace}: socket replaced; will not reconnect`);
this._emit('offline.replaced', event);
break;
case 1001:
case 1005:
case 1006:
case 1011:
this.logger.info('mercury: socket disconnected; reconnecting');
this.logger.info(`${this.namespace}: socket disconnected; reconnecting`);
this._emit('offline.transient', event);
this._reconnect(socketUrl);
// metric: disconnect
// if (code == 1011 && reason !== ping error) metric: unexpected disconnect
break;
case 1000:
if (normalReconnectReasons.includes(reason)) {
this.logger.info('mercury: socket disconnected; reconnecting');
this.logger.info(`${this.namespace}: socket disconnected; reconnecting`);
this._emit('offline.transient', event);
this._reconnect(socketUrl);
// metric: disconnect
// if (reason === done forced) metric: force closure
} else {
this.logger.info('mercury: socket disconnected; will not reconnect');
this.logger.info(`${this.namespace}: socket disconnected; will not reconnect`);
this._emit('offline.permanent', event);
}
break;
default:
this.logger.info('mercury: socket disconnected unexpectedly; will not reconnect');
this.logger.info(
`${this.namespace}: socket disconnected unexpectedly; will not reconnect`
);
// unexpected disconnect
this._emit('offline.permanent', event);
}
} catch (error) {
this.logger.error('mercury: error occurred in close handler', error);
this.logger.error(`${this.namespace}: error occurred in close handler`, error);
}
},

_onmessage(event) {
const envelope = event.data;

if (process.env.ENABLE_MERCURY_LOGGING) {
this.logger.debug('mercury: message envelope: ', envelope);
this.logger.debug(`${this.namespace}: message envelope: `, envelope);
}

const {data} = envelope;
Expand All @@ -468,7 +474,7 @@ const Mercury = WebexPlugin.extend({
resolve((this.webex[namespace] || this.webex.internal[namespace])[name](data))
).catch((reason) =>
this.logger.error(
`mercury: error occurred in autowired event handler for ${data.eventType}`,
`${this.namespace}: error occurred in autowired event handler for ${data.eventType}`,
reason
)
);
Expand All @@ -487,12 +493,12 @@ const Mercury = WebexPlugin.extend({
}
})
.catch((reason) => {
this.logger.error('mercury: error occurred processing socket message', reason);
this.logger.error(`${this.namespace}: error occurred processing socket message`, reason);
});
},

_reconnect(webSocketUrl) {
this.logger.info('mercury: reconnecting');
this.logger.info(`${this.namespace}: reconnecting`);

return this.connect(webSocketUrl);
},
Expand Down
Loading

0 comments on commit f209d78

Please sign in to comment.