"use strict";
const events = require("events");
const RequestTracker = require("./request-tracker");
const errors = require("../errors");
const { format } = require("util");
const nanosToMillis = 1000000;
const defaultMessageMaxQueryLength = 500;
const defaultMaxParameterValueLength = 50;
const defaultMaxErrorStackTraceLength = 200;
/**
* A request tracker that logs the requests executed through the session, according to a set of
* configurable options.
* @implements {module:tracker~RequestTracker}
* @alias module:tracker~RequestLogger
* @example <caption>Logging slow queries</caption>
* const requestLogger = new RequestLogger({ slowThreshold: 1000 });
* requestLogger.emitter.on('show', message => console.log(message));
* // Add the requestLogger to the client options
* const client = new Client({ contactPoints, requestTracker: requestLogger });
*/
class RequestLogger extends RequestTracker {
/**
* Creates a new instance of {@link RequestLogger}.
* @param {Object} options
* @param {Number} [options.slowThreshold] The threshold in milliseconds beyond which queries are considered 'slow'
* and logged as such by the driver.
* @param {Number} [options.requestSizeThreshold] The threshold in bytes beyond which requests are considered 'large'
* and logged as such by the driver.
* @param {Boolean} [options.logNormalRequests] Determines whether it should emit 'normal' events for every
* EXECUTE, QUERY and BATCH request executed successfully, useful only for debugging. This option can be modified
* after the client is connected using the property {@link RequestLogger#logNormalRequests}.
* @param {Boolean} [options.logErroredRequests] Determines whether it should emit 'failure' events for every
* EXECUTE, QUERY and BATCH request execution that resulted in an error. This option can be modified
* after the client is connected using the property {@link RequestLogger#logErroredRequests}.
* @param {Number} [options.messageMaxQueryLength] The maximum amount of characters that are logged from the query
* portion of the message. Defaults to 500.
* @param {Number} [options.messageMaxParameterValueLength] The maximum amount of characters of each query parameter
* value that will be included in the message. Defaults to 50.
* @param {Number} [options.messageMaxErrorStackTraceLength] The maximum amount of characters of the stack trace
* that will be included in the message. Defaults to 200.
*/
constructor(options) {
super();
if (!options) {
throw new errors.ArgumentError(
"RequestLogger options parameter is required",
);
}
this._options = options;
/**
* Determines whether it should emit 'normal' events for every EXECUTE, QUERY and BATCH request executed
* successfully, useful only for debugging
* @type {Boolean}
*/
this.logNormalRequests = this._options.logNormalRequests;
/**
* Determines whether it should emit 'failure' events for every EXECUTE, QUERY and BATCH request execution that
* resulted in an error
* @type {Boolean}
*/
this.logErroredRequests = this._options.logErroredRequests;
/**
* The object instance that emits `'slow'`, `'large'`, `'normal'` and
* `'failure'` events.
* @type {EventEmitter}
*/
this.emitter = new events.EventEmitter();
}
/**
* Logs message if request execution was deemed too slow, large or if normal requests are logged.
* @override
*/
onSuccess(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
) {
if (
this._options.slowThreshold > 0 &&
toMillis(latency) > this._options.slowThreshold
) {
this._logSlow(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
);
} else if (
this._options.requestSizeThreshold > 0 &&
requestLength > this._options.requestSizeThreshold
) {
this._logLargeRequest(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
);
} else if (this.logNormalRequests) {
this._logNormalRequest(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
);
}
}
/**
* Logs message if request execution was too large and/or encountered an error.
* @override
*/
onError(host, query, parameters, execOptions, requestLength, err, latency) {
if (
this._options.requestSizeThreshold > 0 &&
requestLength > this._options.requestSizeThreshold
) {
this._logLargeErrorRequest(
host,
query,
parameters,
execOptions,
requestLength,
err,
latency,
);
} else if (this.logErroredRequests) {
this._logErrorRequest(
host,
query,
parameters,
execOptions,
requestLength,
err,
latency,
);
}
}
_logSlow(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
) {
const message = format(
"[%s] Slow request, took %d ms (%s): %s",
host.address,
Math.floor(toMillis(latency)),
getPayloadSizes(requestLength, responseLength),
getStatementInfo(query, parameters, execOptions, this._options),
);
this.emitter.emit("slow", message);
}
_logLargeRequest(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
) {
const message = format(
"[%s] Request exceeded length, %s (took %d ms): %s",
host.address,
getPayloadSizes(requestLength, responseLength),
~~toMillis(latency),
getStatementInfo(query, parameters, execOptions, this._options),
);
this.emitter.emit("large", message);
}
_logNormalRequest(
host,
query,
parameters,
execOptions,
requestLength,
responseLength,
latency,
) {
const message = format(
"[%s] Request completed normally, took %d ms (%s): %s",
host.address,
~~toMillis(latency),
getPayloadSizes(requestLength, responseLength),
getStatementInfo(query, parameters, execOptions, this._options),
);
this.emitter.emit("normal", message);
}
_logLargeErrorRequest(
host,
query,
parameters,
execOptions,
requestLength,
err,
latency,
) {
const maxStackTraceLength =
this._options.messageMaxErrorStackTraceLength ||
defaultMaxErrorStackTraceLength;
const message = format(
"[%s] Request exceeded length and execution failed, %s (took %d ms): %s; error: %s",
host.address,
getPayloadSizes(requestLength),
~~toMillis(latency),
getStatementInfo(query, parameters, execOptions, this._options),
err.stack.substr(0, maxStackTraceLength),
);
// Use 'large' event and not 'failure' as this log is caused by exceeded length
this.emitter.emit("large", message);
}
_logErrorRequest(
host,
query,
parameters,
execOptions,
requestLength,
err,
latency,
) {
const maxStackTraceLength =
this._options.messageMaxErrorStackTraceLength ||
defaultMaxErrorStackTraceLength;
const message = format(
"[%s] Request execution failed, took %d ms (%s): %s; error: %s",
host.address,
~~toMillis(latency),
getPayloadSizes(requestLength),
getStatementInfo(query, parameters, execOptions, this._options),
err.stack.substr(0, maxStackTraceLength),
);
// Avoid using 'error' as its a special event
this.emitter.emit("failure", message);
}
}
function toMillis(latency) {
return latency[0] * 1000 + latency[1] / nanosToMillis;
}
function getStatementInfo(query, parameters, execOptions, options) {
const maxQueryLength =
options.messageMaxQueryLength || defaultMessageMaxQueryLength;
const maxParameterLength =
options.messageMaxParameterValueLength ||
defaultMaxParameterValueLength;
if (Array.isArray(query)) {
return getBatchStatementInfo(
query,
execOptions,
maxQueryLength,
maxParameterLength,
);
}
// String concatenation is usually faster than Array#join() in V8
let message = query.substr(0, maxQueryLength);
const remaining = maxQueryLength - message.length - 1;
message += getParametersInfo(parameters, remaining, maxParameterLength);
if (!execOptions.isPrepared()) {
// This part of the message is not accounted for in "maxQueryLength"
message += " (not prepared)";
}
return message;
}
function getBatchStatementInfo(
queries,
execOptions,
maxQueryLength,
maxParameterLength,
) {
// This part of the message is not accounted for in "maxQueryLength"
let message =
(execOptions.isBatchLogged() ? "LOGGED " : "") +
"BATCH w/ " +
queries.length +
(!execOptions.isPrepared() ? " not prepared" : "") +
" queries (";
let remaining = maxQueryLength;
let i;
for (i = 0; i < queries.length && remaining > 0; i++) {
let q = queries[i];
const params = q.params;
if (typeof q !== "string") {
q = q.query;
}
if (i > 0) {
message += ",";
remaining--;
}
const queryLength = Math.min(remaining, q.length);
message += q.substr(0, queryLength);
remaining -= queryLength;
if (remaining <= 0) {
break;
}
const parameters = getParametersInfo(
params,
remaining,
maxParameterLength,
);
remaining -= parameters.length;
message += parameters;
}
message += i < queries.length ? ",...)" : ")";
return message;
}
function getParametersInfo(params, remaining, maxParameterLength) {
if (remaining <= 3) {
// We need at least 3 chars to describe the parameters
// its OK to add more chars in an effort to be descriptive
return " [...]";
}
if (!params) {
return " []";
}
let paramStringifier = (index, length) =>
formatParam(params[index], length);
if (!Array.isArray(params)) {
const obj = params;
params = Object.keys(params);
paramStringifier = (index, length) => {
const key = params[index];
let result = key.substr(0, length);
const rem = length - result.length - 1;
if (rem <= 0) {
return result;
}
result += ":" + formatParam(obj[key], rem);
return result;
};
}
let message = " [";
let i;
for (i = 0; remaining > 0 && i < params.length; i++) {
if (i > 0) {
message += ",";
remaining--;
}
const paramString = paramStringifier(
i,
Math.min(maxParameterLength, remaining),
);
remaining -= paramString.length;
message += paramString;
}
if (i < params.length) {
message += "...";
}
message += "]";
return message;
}
function formatParam(value, maxLength) {
if (value === undefined) {
return "undefined";
}
if (value === null) {
return "null";
}
return value.toString().substr(0, maxLength);
}
function getPayloadSizes(requestLength, responseLength) {
let message = "request size " + formatSize(requestLength);
if (responseLength !== undefined) {
message += " / response size " + formatSize(responseLength);
}
return message;
}
function formatSize(length) {
return length > 1000
? Math.round(length / 1024) + " KB"
: length + " bytes";
}
module.exports = RequestLogger;