From 8bd9777b0aedd56b81675c3e79fae63432319982 Mon Sep 17 00:00:00 2001 From: Neal Beeken Date: Tue, 2 Mar 2021 16:05:43 -0500 Subject: [PATCH] fix: use emitWarning API for internal messages (#2743) Updates all logging statements to use node's process.emitWarning API. Allows for filtering, capturing and silencing of warnings. NODE-2317, NODE-3114 --- .eslintrc.json | 2 +- lib/collection.js | 5 +- lib/core/auth/scram.js | 3 +- lib/core/connection/logger.js | 1 + lib/core/connection/msg.js | 4 +- lib/core/sdam/topology.js | 3 +- lib/core/tools/smoke_plugin.js | 1 + lib/core/topologies/read_preference.js | 3 +- lib/core/uri_parser.js | 3 +- lib/core/wireprotocol/kill_cursors.js | 3 +- lib/db.js | 12 ++- lib/operations/add_user.js | 3 +- lib/operations/connect.js | 12 +-- lib/utils.js | 96 ++++++++++++++----- lib/write_concern.js | 6 +- test/.eslintrc.json | 6 ++ test/functional/deprecate_warning.test.js | 21 +++- .../server_selection/select_servers.test.js | 1 - 18 files changed, 138 insertions(+), 47 deletions(-) create mode 100644 test/.eslintrc.json diff --git a/.eslintrc.json b/.eslintrc.json index 2ef22d0906..14a24bba16 100644 --- a/.eslintrc.json +++ b/.eslintrc.json @@ -21,7 +21,7 @@ "es/no-destructuring": "error", "es/no-rest-spread-properties": "error", "es/no-spread-elements": "error", - "no-console": "off", + "no-console": "error", "eqeqeq": ["error", "always", { "null": "ignore" }], "strict": ["error", "global"] }, diff --git a/lib/collection.js b/lib/collection.js index 5d1a1c6854..c84f1f9df3 100644 --- a/lib/collection.js +++ b/lib/collection.js @@ -2,6 +2,7 @@ const deprecate = require('util').deprecate; const deprecateOptions = require('./utils').deprecateOptions; +const emitWarningOnce = require('./utils').emitWarningOnce; const checkCollectionName = require('./utils').checkCollectionName; const ObjectID = require('./core').BSON.ObjectID; const MongoError = require('./core').MongoError; @@ -323,7 +324,7 @@ Collection.prototype.find = deprecateOptions( function(query, options, callback) { if (typeof callback === 'object') { // TODO(MAJOR): throw in the future - console.warn('Third parameter to `find()` must be a callback or undefined'); + emitWarningOnce('Third parameter to `find()` must be a callback or undefined'); } let selector = query; @@ -1092,7 +1093,7 @@ Collection.prototype.findOne = deprecateOptions( function(query, options, callback) { if (typeof callback === 'object') { // TODO(MAJOR): throw in the future - console.warn('Third parameter to `findOne()` must be a callback or undefined'); + emitWarningOnce('Third parameter to `findOne()` must be a callback or undefined'); } if (typeof query === 'function') (callback = query), (query = {}), (options = {}); diff --git a/lib/core/auth/scram.js b/lib/core/auth/scram.js index 7b8d7b34ef..7eca32dda3 100644 --- a/lib/core/auth/scram.js +++ b/lib/core/auth/scram.js @@ -4,6 +4,7 @@ const Buffer = require('safe-buffer').Buffer; const retrieveBSON = require('../connection/utils').retrieveBSON; const MongoError = require('../error').MongoError; const AuthProvider = require('./auth_provider').AuthProvider; +const emitWarningOnce = require('../../utils').emitWarning; const BSON = retrieveBSON(); const Binary = BSON.Binary; @@ -24,7 +25,7 @@ class ScramSHA extends AuthProvider { prepare(handshakeDoc, authContext, callback) { const cryptoMethod = this.cryptoMethod; if (cryptoMethod === 'sha256' && saslprep == null) { - console.warn('Warning: no saslprep library specified. Passwords will not be sanitized'); + emitWarningOnce('Warning: no saslprep library specified. Passwords will not be sanitized'); } crypto.randomBytes(24, (err, nonce) => { diff --git a/lib/core/connection/logger.js b/lib/core/connection/logger.js index 3b0be90d6f..b2957a5556 100644 --- a/lib/core/connection/logger.js +++ b/lib/core/connection/logger.js @@ -37,6 +37,7 @@ var Logger = function(className, options) { if (options.logger) { currentLogger = options.logger; } else if (currentLogger == null) { + // eslint-disable-next-line no-console currentLogger = console.log; } diff --git a/lib/core/connection/msg.js b/lib/core/connection/msg.js index 9f15a81114..e241c096af 100644 --- a/lib/core/connection/msg.js +++ b/lib/core/connection/msg.js @@ -31,6 +31,7 @@ const Buffer = require('safe-buffer').Buffer; const opcodes = require('../wireprotocol/shared').opcodes; const databaseNamespace = require('../wireprotocol/shared').databaseNamespace; const ReadPreference = require('../topologies/read_preference'); +const MongoError = require('../../core/error').MongoError; // Incrementing request id let _requestId = 0; @@ -196,7 +197,8 @@ class BinMsg { while (this.index < this.data.length) { const payloadType = this.data.readUInt8(this.index++); if (payloadType === 1) { - console.error('TYPE 1'); + // It was decided that no driver makes use of payload type 1 + throw new MongoError('OP_MSG Payload Type 1 detected unsupported protocol'); } else if (payloadType === 0) { const bsonSize = this.data.readUInt32LE(this.index); const bin = this.data.slice(this.index, this.index + bsonSize); diff --git a/lib/core/sdam/topology.js b/lib/core/sdam/topology.js index 82677692a1..f18f7785c8 100644 --- a/lib/core/sdam/topology.js +++ b/lib/core/sdam/topology.js @@ -27,6 +27,7 @@ const ServerSessionPool = require('../sessions').ServerSessionPool; const makeClientMetadata = require('../utils').makeClientMetadata; const CMAP_EVENT_NAMES = require('../../cmap/events').CMAP_EVENT_NAMES; const compareTopologyVersion = require('./server_description').compareTopologyVersion; +const emitWarning = require('../../utils').emitWarning; const common = require('./common'); const drainTimerQueue = common.drainTimerQueue; @@ -739,7 +740,7 @@ class Topology extends EventEmitter { } unref() { - console.log('not implemented: `unref`'); + emitWarning('not implemented: `unref`'); } // NOTE: There are many places in code where we explicitly check the last isMaster diff --git a/lib/core/tools/smoke_plugin.js b/lib/core/tools/smoke_plugin.js index 22d0298627..7488f0f1dc 100644 --- a/lib/core/tools/smoke_plugin.js +++ b/lib/core/tools/smoke_plugin.js @@ -52,6 +52,7 @@ exports.attachToRunner = function(runner, outputFile) { fs.writeFileSync(outputFile, JSON.stringify(smokeOutput)); // Standard NodeJS uncaught exception handler + // eslint-disable-next-line no-console console.error(err.stack); process.exit(1); }); diff --git a/lib/core/topologies/read_preference.js b/lib/core/topologies/read_preference.js index d4627721ff..afd2362f76 100644 --- a/lib/core/topologies/read_preference.js +++ b/lib/core/topologies/read_preference.js @@ -1,4 +1,5 @@ 'use strict'; +const emitWarningOnce = require('../../utils').emitWarningOnce; /** * The **ReadPreference** class is a class that represents a MongoDB ReadPreference and is @@ -20,7 +21,7 @@ const ReadPreference = function(mode, tags, options) { // TODO(major): tags MUST be an array of tagsets if (tags && !Array.isArray(tags)) { - console.warn( + emitWarningOnce( 'ReadPreference tags must be an array, this will change in the next major version' ); diff --git a/lib/core/uri_parser.js b/lib/core/uri_parser.js index 62584a8899..bcb7dd3748 100644 --- a/lib/core/uri_parser.js +++ b/lib/core/uri_parser.js @@ -4,6 +4,7 @@ const qs = require('querystring'); const dns = require('dns'); const MongoParseError = require('./error').MongoParseError; const ReadPreference = require('./topologies/read_preference'); +const emitWarningOnce = require('../utils').emitWarningOnce; /** * The following regular expression validates a connection string and breaks the @@ -438,7 +439,7 @@ function parseQueryString(query, options) { // special cases for known deprecated options if (result.wtimeout && result.wtimeoutms) { delete result.wtimeout; - console.warn('Unsupported option `wtimeout` specified'); + emitWarningOnce('Unsupported option `wtimeout` specified'); } return Object.keys(result).length ? result : null; diff --git a/lib/core/wireprotocol/kill_cursors.js b/lib/core/wireprotocol/kill_cursors.js index bb1347737f..22744794f9 100644 --- a/lib/core/wireprotocol/kill_cursors.js +++ b/lib/core/wireprotocol/kill_cursors.js @@ -5,6 +5,7 @@ const MongoError = require('../error').MongoError; const MongoNetworkError = require('../error').MongoNetworkError; const collectionNamespace = require('./shared').collectionNamespace; const maxWireVersion = require('../utils').maxWireVersion; +const emitWarning = require('../utils').emitWarning; const command = require('./command'); function killCursors(server, ns, cursorState, callback) { @@ -31,7 +32,7 @@ function killCursors(server, ns, cursorState, callback) { if (typeof callback === 'function') { callback(err, null); } else { - console.warn(err); + emitWarning(err); } } } diff --git a/lib/db.js b/lib/db.js index 40c51f9e21..18b9af5aec 100644 --- a/lib/db.js +++ b/lib/db.js @@ -12,7 +12,7 @@ const MongoError = require('./core').MongoError; const ObjectID = require('./core').ObjectID; const Logger = require('./core').Logger; const Collection = require('./collection'); -const mergeOptionsAndWriteConcern = require('./utils').mergeOptionsAndWriteConcern; +const conditionallyMergeWriteConcern = require('./utils').conditionallyMergeWriteConcern; const executeLegacyOperation = require('./utils').executeLegacyOperation; const ChangeStream = require('./change_stream'); const deprecate = require('util').deprecate; @@ -382,7 +382,7 @@ Db.prototype.admin = function() { * @param {AggregationCursor} cursor The cursor if the aggregation command was executed successfully. */ -const collectionKeys = [ +const COLLECTION_OPTION_KEYS = [ 'pkFactory', 'readPreference', 'serializeFunctions', @@ -433,8 +433,14 @@ Db.prototype.collection = function(name, options, callback) { options.ignoreUndefined = this.s.options.ignoreUndefined; } + for (const collectionOptionKey of COLLECTION_OPTION_KEYS) { + if (!(collectionOptionKey in options) && this.s.options[collectionOptionKey] !== undefined) { + options[collectionOptionKey] = this.s.options[collectionOptionKey]; + } + } + // Merge in all needed options and ensure correct writeConcern merging from db level - options = mergeOptionsAndWriteConcern(options, this.s.options, collectionKeys, true); + options = conditionallyMergeWriteConcern(options, this.s.options, COLLECTION_OPTION_KEYS, true); // Execute if (options == null || !options.strict) { diff --git a/lib/operations/add_user.js b/lib/operations/add_user.js index 9c025107ba..62af9d8039 100644 --- a/lib/operations/add_user.js +++ b/lib/operations/add_user.js @@ -6,6 +6,7 @@ const defineAspects = require('./operation').defineAspects; const crypto = require('crypto'); const handleCallback = require('../utils').handleCallback; const toError = require('../utils').toError; +const emitWarning = require('../utils').emitWarning; class AddUserOperation extends CommandOperation { constructor(db, username, password, options) { @@ -29,7 +30,7 @@ class AddUserOperation extends CommandOperation { // If not roles defined print deprecated message // TODO: handle deprecation properly if (roles.length === 0) { - console.log('Creating a user without roles is deprecated in MongoDB >= 2.6'); + emitWarning('Creating a user without roles is deprecated in MongoDB >= 2.6'); } // Check the db name and add roles if needed diff --git a/lib/operations/connect.js b/lib/operations/connect.js index 2f3bff96bf..9d122a2fa9 100644 --- a/lib/operations/connect.js +++ b/lib/operations/connect.js @@ -13,6 +13,7 @@ const ReplSet = require('../topologies/replset'); const Server = require('../topologies/server'); const ServerSessionPool = require('../core').Sessions.ServerSessionPool; const emitDeprecationWarning = require('../utils').emitDeprecationWarning; +const emitWarningOnce = require('../utils').emitWarningOnce; const fs = require('fs'); const WriteConcern = require('../write_concern'); const BSON = require('../core/connection/utils').retrieveBSON(); @@ -182,12 +183,12 @@ function validOptions(options) { if (options.validateOptions) { return new MongoError(`option ${name} is not supported`); } else { - console.warn(`the options [${name}] is not supported`); + emitWarningOnce(`the options [${name}] is not supported`); } } if (legacyOptionNames.indexOf(name) !== -1) { - console.warn( + emitWarningOnce( `the server/replset/mongos/db options are deprecated, ` + `all their options are supported at the top level of the options object [${validOptionNames}]` ); @@ -257,9 +258,6 @@ function resolveTLSOptions(options) { }); } -const emitDeprecationForNonUnifiedTopology = deprecate(() => {}, -'current Server Discovery and Monitoring engine is deprecated, and will be removed in a future version. ' + 'To use the new Server Discover and Monitoring engine, pass option { useUnifiedTopology: true } to the MongoClient constructor.'); - function connect(mongoClient, url, options, callback) { options = Object.assign({}, options); @@ -335,7 +333,9 @@ function connect(mongoClient, url, options, callback) { return createTopology(mongoClient, 'unified', _finalOptions, connectCallback); } - emitDeprecationForNonUnifiedTopology(); + emitWarningOnce( + 'Current Server Discovery and Monitoring engine is deprecated, and will be removed in a future version. To use the new Server Discover and Monitoring engine, pass option { useUnifiedTopology: true } to the MongoClient constructor.' + ); // Do we have a replicaset then skip discovery and go straight to connectivity if (_finalOptions.replicaSet || _finalOptions.rs_name) { diff --git a/lib/utils.js b/lib/utils.js index 0ebbb4565a..b698a90272 100644 --- a/lib/utils.js +++ b/lib/utils.js @@ -287,39 +287,38 @@ var filterOptions = function(options, names) { }; // Write concern keys -var writeConcernKeys = ['w', 'j', 'wtimeout', 'fsync']; +const WRITE_CONCERN_KEYS = ['w', 'j', 'wtimeout', 'fsync', 'writeConcern']; -// Merge the write concern options -var mergeOptionsAndWriteConcern = function(targetOptions, sourceOptions, keys, mergeWriteConcern) { - // Mix in any allowed options - for (var i = 0; i < keys.length; i++) { - if (!targetOptions[keys[i]] && sourceOptions[keys[i]] !== undefined) { - targetOptions[keys[i]] = sourceOptions[keys[i]]; - } - } - - // No merging of write concern - if (!mergeWriteConcern) return targetOptions; - - // Found no write Concern options - var found = false; - for (i = 0; i < writeConcernKeys.length; i++) { - if (targetOptions[writeConcernKeys[i]]) { +/** + * If there is no WriteConcern related options defined on target then inherit from source. + * Otherwise, do not inherit **any** options from source. + * @internal + * @param {object} target - options object conditionally receiving the writeConcern options + * @param {object} source - options object containing the potentially inherited writeConcern options + */ +function conditionallyMergeWriteConcern(target, source) { + let found = false; + for (const wcKey of WRITE_CONCERN_KEYS) { + if (wcKey in target) { + // Found a writeConcern option found = true; break; } } if (!found) { - for (i = 0; i < writeConcernKeys.length; i++) { - if (sourceOptions[writeConcernKeys[i]]) { - targetOptions[writeConcernKeys[i]] = sourceOptions[writeConcernKeys[i]]; + for (const wcKey of WRITE_CONCERN_KEYS) { + if (source[wcKey]) { + if (!('writeConcern' in target)) { + target.writeConcern = {}; + } + target.writeConcern[wcKey] = source[wcKey]; } } } - return targetOptions; -}; + return target; +} /** * Executes the given operation with provided arguments. @@ -534,7 +533,9 @@ function decorateWithExplain(command, explain) { return { explain: command, verbosity: explain.verbosity }; } -const emitProcessWarning = msg => process.emitWarning(msg, 'DeprecationWarning'); +const emitProcessWarning = msg => + process.emitWarning(msg, { type: 'DeprecationWarning', code: MONGODB_WARNING_CODE }); +// eslint-disable-next-line no-console const emitConsoleWarning = msg => console.error(msg); const emitDeprecationWarning = process.emitWarning ? emitProcessWarning : emitConsoleWarning; @@ -816,6 +817,48 @@ function hasAtomicOperators(doc) { ); } +/** + * When the driver used emitWarning the code will be equal to this. + * @public + * + * @example + * ```js + * process.on('warning', (warning) => { + * if (warning.code === MONGODB_WARNING_CODE) console.error('Ah an important warning! :)') + * }) + * ``` + */ +const MONGODB_WARNING_CODE = 'MONGODB DRIVER'; + +/** + * @internal + * @param {string} message - message to warn about + */ +function emitWarning(message) { + if (process.emitWarning) { + return process.emitWarning(message, { code: MONGODB_WARNING_CODE }); + } else { + // Approximate the style of print out on node versions pre 8.x + // eslint-disable-next-line no-console + return console.error(`[${MONGODB_WARNING_CODE}] Warning:`, message); + } +} + +const emittedWarnings = new Set(); +/** + * Will emit a warning once for the duration of the application. + * Uses the message to identify if it has already been emitted + * so using string interpolation can cause multiple emits + * @internal + * @param {string} message - message to warn about + */ +function emitWarningOnce(message) { + if (!emittedWarnings.has(message)) { + emittedWarnings.add(message); + return emitWarning(message); + } +} + module.exports = { filterOptions, mergeOptions, @@ -832,7 +875,7 @@ module.exports = { isObject, debugOptions, MAX_JS_INT: Number.MAX_SAFE_INTEGER + 1, - mergeOptionsAndWriteConcern, + conditionallyMergeWriteConcern, executeLegacyOperation, applyRetryableWrites, applyWriteConcern, @@ -849,5 +892,8 @@ module.exports = { now, calculateDurationInMs, makeInterruptableAsyncInterval, - hasAtomicOperators + hasAtomicOperators, + MONGODB_WARNING_CODE, + emitWarning, + emitWarningOnce }; diff --git a/lib/write_concern.js b/lib/write_concern.js index 5d0e1701f6..8fa487403b 100644 --- a/lib/write_concern.js +++ b/lib/write_concern.js @@ -1,6 +1,7 @@ 'use strict'; const kWriteConcernKeys = new Set(['w', 'wtimeout', 'j', 'journal', 'fsync']); +let utils; /** * The **WriteConcern** class is a class that represents a MongoDB WriteConcern. @@ -75,7 +76,10 @@ class WriteConcern { ); } - console.warn( + // this is down here to prevent circular dependency + if (!utils) utils = require('./utils'); + + utils.emitWarningOnce( `Top-level use of w, wtimeout, j, and fsync is deprecated. Use writeConcern instead.` ); return new WriteConcern( diff --git a/test/.eslintrc.json b/test/.eslintrc.json new file mode 100644 index 0000000000..513987db1a --- /dev/null +++ b/test/.eslintrc.json @@ -0,0 +1,6 @@ +{ + "extends": "../.eslintrc.json", + "rules": { + "no-console": "off" + } +} diff --git a/test/functional/deprecate_warning.test.js b/test/functional/deprecate_warning.test.js index 726d246f42..cbbb98ea98 100644 --- a/test/functional/deprecate_warning.test.js +++ b/test/functional/deprecate_warning.test.js @@ -1,4 +1,6 @@ 'use strict'; +const MongoClient = require('../../index').MongoClient; +const MONGODB_WARNING_CODE = require('../../lib/utils').MONGODB_WARNING_CODE; const exec = require('child_process').exec; const chai = require('chai'); const expect = chai.expect; @@ -35,6 +37,22 @@ describe('Deprecation Warnings', function() { } }); + it('should carry the driver warning code', { + metadata: { requires: { node: '>=8.0.0' } }, + test() { + const client = new MongoClient(this.configuration.url(), { madeUpOption: 3 }); + let warning; + process.once('warning', w => { + warning = w; + }); + return client.connect().then(() => { + expect(warning).to.exist; + expect(warning.code).to.equal(MONGODB_WARNING_CODE); + return client.close(); + }); + } + }); + it('node --trace-deprecation flag should print stack trace to stderr', { metadata: { requires: { node: '>=6.0.0' } }, test: function(done) { @@ -54,7 +72,8 @@ describe('Deprecation Warnings', function() { // ensure warning message matches expected expect(warning).to.equal( - 'DeprecationWarning: testDeprecationFlags option [maxScan]' + defaultMessage + '[MONGODB DRIVER] DeprecationWarning: testDeprecationFlags option [maxScan]' + + defaultMessage ); // ensure each following line is from the stack trace, i.e. 'at config.deprecatedOptions.forEach.deprecatedOption' diff --git a/test/unit/sdam/server_selection/select_servers.test.js b/test/unit/sdam/server_selection/select_servers.test.js index 218b3f76f6..b85b2de874 100644 --- a/test/unit/sdam/server_selection/select_servers.test.js +++ b/test/unit/sdam/server_selection/select_servers.test.js @@ -85,7 +85,6 @@ describe('selectServer', function() { let completed = 0; function finish() { completed++; - console.log(completed); if (completed === toSelect) done(); }