/* * Copyright DataStax, Inc. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ '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
'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;