Node Debugging Tools (a work in progress)

debugTools.js

"use strict";

const realConsole = console;

var debugTools = {

    defaultOptions: {
        enhanceConsoleLog: false,

        listenForUnhandledRejections: true,
        reportLongStackTraces: true,
        promisesAlwaysRejectWithError: false,

        // @todo These next three can be considered sane defaults for mongoose
        //       They could be enabled by default, because they are helpful to developers
        //       Existing projects which do not want to use them can disable them when calling debugTools.init()
        mongooseForceStrictSchemas: false,
        mongooseMakeFieldsRequiredByDefault: false,   // @todo Implement this
        mongooseReportIndexingErrors: true,           // @todo Implement this
        mongooseEnableStrictQuery: true,              // @todo Implement this
        mongooseUpsertsMustUseUniqueIndex: true,      // @todo Implement this
        mongooseLogEachQuery: false,
        // This will periodically log the number of active (uncompleted) mongoose queries, if there are more than the threshold.
        // It can provide an early warning if there are more queries than the DB can handle, although it does not tell you which queries they are.
        mongooseCountQueries: false,
        mongooseCountQueriesInterval: 1000,
        mongooseCountQueriesMinQueriesForLog: 10,
        // @todo One annoying aspect of mongoose is that the details of validation errors are hard to reach.  (They got lost if the error is stringified or JSONified.  We have to look inside error.errors to find them!)
        //       Can we somehow intercept these errors on the way out of mongoose, and put the details into the error message, for developer convenience?

        logAllFunctionCalls: false,
        logSetTimeouts: false,
        warnAboutUnclosedWebSocketClients: false,
        warnAboutDisconnectedWebSocketClients: false,

        checkForMemoryLeaks: false,
        // Turns logging of memory usage on/off.  (Logging occurs immediately after a garbage collection.)
        logMemoryUsage: false,
        // Will only log memory usage if it exceeds this many megabytes
        logMemoryUsageMinimum: 200,
        saveHeapDumpWhenLeakIsDetected: false,
        // Diffing two subsequent heaps will show which type of object is causing the memory leak.
        // But heap snapshots and especially diffing will lock up the process.  So not recommended for production!
        performHeapDiffWhenLeakIsDetected: false,
        // In some environments (nodejs v6.9.0), memwatch-next's automatic leak detection triggers too early, due to lots of small gcs while the app is starting.  This lets us ignore it when the memory usage is still low.
        ignoreMemLeakBelow: 250,
        // Sometimes memwatch-next's automatic leak detection fails to trigger because Node performs double-GCs which confuse it.  To work around this, we can trigger a fake 'leak' event if the memory usage exceeds the given value.
        assumeLeakWhenMemReaches: 2048,
    },

    developmentOptions: {
        enhanceConsoleLog: true,
        mongooseCountQueriesInterval: 2000,
        mongooseCountQueriesMinQueriesForLog: 100,
        warnAboutUnclosedWebSocketClients: true,
        warnAboutDisconnectedWebSocketClients: true,
        performHeapDiffWhenLeakIsDetected: true,
    },

    init: function (_options) {
        const options = Object.assign({}, debugTools.defaultOptions, _options || {});


        const promiseDebugging = require('./promiseDebugging');

        // This config object could be deprecated.  We can auto-detect which promise libs are present.
        const pdConfig = {
            Q: true,
            BlueBird: false,
            global: true,
            mongoose: false,
        };

        if (options.listenForUnhandledRejections) {
            promiseDebugging.listenForUnhandledRejections(pdConfig);
        }

        // Displays the location of each line printed on console.log
        if (options.enhanceConsoleLog) {
            require('./contrib/enhance_console_log');
        }

        // Log every module function that is called (almost a full function trace)
        // BUG: If you use this *and* enhance_console_log, but enhance_console_log is required *after* this, then we exceed maximum stack size (infloop).
        if (options.logAllFunctionCalls) {
            debugTools.wrapAllModulesWithLogging();
        }

        // Logs the queries that Mongoose sends to Mongo  (A bit noisy!  Does not log response data.)
        if (options.mongooseLogEachQuery) {
            require('mongoose').set('debug', true);
        }

        // Watches the requests and responses of mongoose queries so it can display the number of active (pending) queries.
        // We could also use this to log response data if we wanted to.
        if (options.mongooseCountQueries) {
            // We could record and clear the member names (maybe also stack query object) of all called queries, so we can display the details of queries which did not return.

            let queriesMade = 0;
            let queriesFinished = 0;

            const logQueryState = function () {
                const activeQueries = queriesMade - queriesFinished;
                if (activeQueries >= options.mongooseCountQueriesMinQueriesForLog) {
                    console.info("[mongooseCountQueries]  Active: %s  Completed: %s / %s", activeQueries.toLocaleString(), queriesFinished.toLocaleString(), queriesMade.toLocaleString());
                }
            };

            const NativeCollection = require('mongoose/lib/drivers/node-mongodb-native/collection.js');
            const driver = NativeCollection.prototype;
            for (const prop in driver) {
                // Not all members of the driver are query functions.  Some we should ignore.
                const skip = prop === 'addQueue' || prop === 'doQueue' || prop[0] === '$';
                if (skip) {
                    continue;
                }
                const member = driver[prop];
                if (typeof member === 'function') {
                    //console.log(`Wrapping driver.${prop}`);
                    const wrappedFunc = (function (originalFunc) {
                        return function () {
                            let returnVal;
                            const lastArgument = arguments[arguments.length - 1];
                            const looksLikeCallback = typeof lastArgument === 'function';
                            if (looksLikeCallback) {
                                const originalCallback = lastArgument;
                                const newArgs = Array.prototype.splice.call(arguments, 0);
                                const wrappedCallback = function () {
                                    queriesFinished++;
                                    return originalCallback.apply(this, arguments);
                                };
                                newArgs[newArgs.length - 1] = wrappedCallback;
                                returnVal = originalFunc.apply(this, newArgs);
                            } else {
                                // With the driver we are currently wrapping, I think only callbacks are used, never promises, so this code could be removed.
                                const returnedVal = originalFunc.apply(this, arguments);
                                var looksLikePromise = returnedVal && typeof returnedVal.then === 'function';
                                if (looksLikePromise) {
                                    returnVal = returnedVal.then(
                                        result => {
                                            queriesFinished++;
                                            //logQueryState();
                                            return result;
                                        },
                                        error => {
                                            queriesFinished++;
                                            //logQueryState();
                                            throw error;
                                        }
                                    );
                                } else {
                                    returnVal = returnedVal;
                                }
                            }
                            if (looksLikeCallback || looksLikePromise) {
                                queriesMade++;
                                //logQueryState();
                            }
                            return returnVal;
                        };
                    }(member));
                    driver[prop] = wrappedFunc;
                }
            }

            let queriesMadePrevious = 0;
            let queriesFinishedPrevious = 0;
            setInterval(function () {
                if (queriesMade !== queriesMadePrevious || queriesFinished !== queriesFinishedPrevious) {
                    logQueryState();
                }
                queriesMadePrevious = queriesMade;
                queriesFinishedPrevious = queriesFinished;
            }, options.mongooseCountQueriesInterval);
        }

        // Shows long stack-traces (where a promise was initialised from) but has a performance overhead.
        //require('./promiseDebugging').setDefaults();
        if (options.reportLongStackTraces) {
            promiseDebugging.reportLongStackTraces(pdConfig);
        }

        // Provides long stack traces for all callbacks, not just promises
        // Does a better job on mongoose queries than promiseDebugging does, but it is a bit verbose!
        if (moduleIsAvailable('longjohn')) {
            const longjohn = require('longjohn');

            longjohn.async_trace_limit = 15;
            longjohn.empty_frame = 'Called from:';
        }

        // Provides shorter stack traces by removing uninteresting Node-core frames
        if (moduleIsAvailable('clarify')) {
            require('clarify');
        }

        if (options.promisesAlwaysRejectWithError) {
            promiseDebugging.alwaysRejectWithError();
        }

        if (options.mongooseForceStrictSchemas) {
            // This tool will warn us if we try to create documents with fields not in the schema.
            // Mongoose's default behaviour is to ignore (drop) fields which are not in the schema.
            // Warning can help development by informing us when we perform queries with mistakes or typos.
            // But at present it breaks our tests, because they pass some unspecified fields.
            const mongoose = require('mongoose');
            const originalSchema = mongoose.Schema;
            const wrappedSchema = function (definition, options) {
                options = options || {};
                options.strict = 'throw';
                return originalSchema.call(mongoose, definition, options);
            };
            Object.assign(wrappedSchema, originalSchema);
            Object.setPrototypeOf(wrappedSchema, Object.getPrototypeOf(originalSchema));
            mongoose.Schema = wrappedSchema;
        }

        // @consider: Monkey-patch mongo to warn if we query a model for fields which don't exist.  (E.g. we query on 'platform' but the schema specified 'platformId'.)

        // Look out for memory leaks.  If a leak is detected, try to find out what classes are growing in number.
        if (options.checkForMemoryLeaks && !moduleIsAvailable('memwatch-next')) {
            console.warn("Can not check for memory leaks because memwatch-next is not installed.");
        }
        if (options.saveHeapDumpWhenLeakIsDetected && !moduleIsAvailable('heapdump')) {
            console.warn("Can not save heap dumps because heapdump is not installed.");
        }
        if (options.checkForMemoryLeaks && moduleIsAvailable('memwatch-next')) {
            console.log(`Watching for memory leaks with memwatch-next`);

            const startTime = Date.now();
            const secondsFromStart = () => '[' + roundNum((Date.now() - startTime) / 1000) + ']';
            var roundNum = num => num.toFixed(3);

            const memwatch = require('memwatch-next');

            let leakDetected = false;
            let heapDiff;

            if (options.saveHeapDumpWhenLeakIsDetected && moduleIsAvailable('heapdump')) {
                // Allows a heap dump to be triggered externally with: kill -USR2 <pid>
                require('heapdump');
            }
            const maxHeapDumpsToSave = 5;
            let numHeapDumpsSaved = 0;

            memwatch.on('leak', function (info) {
                console.warn("Possible memory leak detected:", JSON.stringify(info));
                leakDetected = true;
                // We leave it to the 'stats' event to snapshot and diff heaps
                // We don't do it here because it can be a very long time between two 'leak' events, resulting in large and different heaps.
            });

            // When the memory is large (1GB) the diff takes too long, locking up the server.
            // The heap snapshot takes about 8 seconds, the diff takes about 50 seconds.
            // A better approach might be to save the two heap snapshots to a file, and diff them later.

            memwatch.on('stats', function (d) {
                const memoryUsageInMegabytes = d.current_base / 1024 / 1024;
                const exceededMinimumExcessiveUsage = options.ignoreMemLeakBelow && memoryUsageInMegabytes >= options.ignoreMemLeakBelow;

                // Garbage collection has just been performed.  This is a good time to check memory usage, or take heap snapshots.
                if (options.logMemoryUsage && (options.logMemoryUsageMinimum !== 'number' || memoryUsageInMegabytes > options.logMemoryUsageMinimum)) {
                    console.log(secondsFromStart(), "Memory usage post-gc:", roundNum(memoryUsageInMegabytes), 'MB');
                }

                // @todo A lot of GCs are coming in close pairs, often with <100ms between them.
                // Ideally we would heapdump only after the second.
                // Should we then debounce the handling below, in case another GC happens in the next second?
                // But we shouldn't debounce with setTimeout, because now (immediately after the GC) is the correct moment to dump.

                if (leakDetected && !exceededMinimumExcessiveUsage) {
                    // It looks like memwatch has detected a memory leak prematurely
                    console.log("Ignoring \"memory leak\" because memory usage is below ignoreMemLeakBelow (" + options.ignoreMemLeakBelow + "MB)");
                    leakDetected = false;
                }

                if (leakDetected && options.saveHeapDumpWhenLeakIsDetected && numHeapDumpsSaved < maxHeapDumpsToSave && moduleIsAvailable('heapdump')) {
                    // We could use this, but I want to disable the signal recognition when I'm using nodemon
                    //console.warn(secondsFromStart(), "Dumping the heap...");
                    //process.kill(process.pid, 'SIGUSR2');
                    //setTimeout(
                    //    () => console.warn(secondsFromStart(), "Heap dump completed."),
                    //    1
                    //);

                    // Anyway this approach gives us more control
                    // We run a few different process in the same folder, so we name the heapdumps to distinguish them.
                    const longerProcessName = getProcessNameWithPath().replace(/\//g, '.');
                    const filename = './heapdump-' + longerProcessName + '-' + process.pid + '-' + numHeapDumpsSaved + '.heapsnapshot';
                    console.warn(secondsFromStart(), "Dumping the heap to " + filename);
                    require('heapdump').writeSnapshot(filename, () => {
                        console.warn(secondsFromStart(), "Heap dump completed.");
                    });

                    numHeapDumpsSaved++;
                }

                if (options.performHeapDiffWhenLeakIsDetected) {
                    // This 'stats' event is fired after every GC, but the 'leak' event is fired before it.
                    // After a leak is detected, we will start a heapDiff, and after the next GC we immediately diff it.
                    if (leakDetected) {
                        if (!heapDiff) {
                            console.warn(secondsFromStart(), "Starting a HeapDiff...");
                            heapDiff = new memwatch.HeapDiff();
                            console.warn(secondsFromStart(), "Heap snapshot captured.");
                        } else {
                            console.warn(secondsFromStart(), "Diffing heap against last...");
                            const diff = heapDiff.end();
                            console.warn(secondsFromStart(), "HeapDiff reports:", diff);
                            // Node cuts off the details of the diff logged above, showing them as "[object Object]", so we show the details like this...
                            let details = diff.change.details.filter(dt => dt.size_bytes > 0);
                            details.sort((a, b) => b.size_bytes - a.size_bytes);
                            details = details.slice(0, 5);
                            console.warn("HeapDiff change details:\n", details);
                            heapDiff = null;
                            // Currently we only capture the two heaps needed for diffing.
                            // Uncomment this if you want to continue detecting leaks and capturing heaps.
                            // But beware that later heaps will get larger and slower.
                            //leakDetected = false;
                        }
                    }
                }

                // Sometimes memwatch does not detect a leak because Node is performing GC in pairs, and the second in some pairs reduce the memory usage, invalidating memwatch's condition of 5 post-GC increases.
                // So we will also trigger a leak detection event if memory usage goes over some threshold.
                // @todo Since our .on('leak') only sets leakDetected = true, we could move this to the top of this function, so the code will take action now rather than on the next GC.
                if (options.assumeLeakWhenMemReaches && memoryUsageInMegabytes > options.assumeLeakWhenMemReaches) {
                    const reason = "Triggering fake leak event because mem usage " + roundNum(memoryUsageInMegabytes) + " MB > " + roundNum(options.assumeLeakWhenMemReaches) + " MB";
                    memwatch.emit('leak', {growth: d.current_base, reason: reason});
                }
            });

            // The heap can be significantly larger in the middle of runtime.
            // It's not an accurate measure of memory usage, because there could be a lot of unreferenced objects which could be collected on the next sweep.
            // That is why we prefer to use the memwatch 'stats' event, which gets called just after GC.
            //setInterval(function () {
            //   console.log(secondsFromStart(), "Memory usage runtime:", roundNum(process.memoryUsage().heapUsed / 1024 / 1024), 'MB');
            //}, 5000);

            const generateTestLeak = false;

            if (generateTestLeak) {
                // Test it
                console.warn("GENERATING A TEST MEMORY LEAK!");
                const bucket = [];

                // setInterval(() => {
                //    for (var i = 0; i < 1000; i++) {
                //        bucket.push(new Date());
                //        bucket.push(new WeakMap());
                //        bucket.push({});
                //        bucket.push("A long string long long long long long long long long long long long long " + i);
                //    }
                // }, 100);

                setInterval(function () {
                    for (let i = 0; i < 2000; i++) {
                        const str = i.toString() + " on a stick, short and stout!";
                        bucket.push(str);
                    }
                }, 100);
            }

        }

        if (options.logSetTimeouts) {
            const originalSetTimeout = setTimeout;
            const wrappedSetTimeout = function () {
                console.log('setTimeout called', new Error().stack.split('\n')[2].trim());
                return originalSetTimeout.apply(this, arguments);
            };
            global.setTimeout = wrappedSetTimeout;
        }

        // The unclosed WebSocket check was primarily for the botRunner.
        // In fact some of our servers want their sockets to remain open, even if they are idle.
        const longLastingSocketsIsNormal = process.argv[1] && (
            process.argv[1].match('/app.js$')
            || process.argv[1].match('/clientAPIServer.js$')
            || process.argv[1].match('/paymentAPIServer.js$')
            || process.argv[1].match('/providerAPIServer.js$')
        );

        if ((options.warnAboutUnclosedWebSocketClients || options.warnAboutDisconnectedWebSocketClients) && !longLastingSocketsIsNormal) {
            const WebSocketClient = require('../server_common/WebSocketClient');

            const checkIdle = function () {
                if (Date.now() > this.__lastActivity + 1000 * 60 * 10) {
                    const idleMinutes = ((Date.now() - this.__lastActivity) / 1000 / 60).toFixed(1);
                    if (this.isOpen()) {
                        // This may indicate a WebSocketClient which we have forgotten to close.
                        // But for some external api server connections, we want to keep them open even when they are idle, so we make the logging optional.
                        if (options.warnAboutUnclosedWebSocketClients) {
                            console.warn(`This WebSocketClient (${this.url}) has not been used for ${idleMinutes} minutes but is still open.  Remember to call .disconnect() on WebSocketClients when you are finished with them.`);
                            // If we don't clear the timer, the warning will continue to be emitted every 2 minutes, as long as the socket stays open.
                            clearInterval(this.__checkIdleTimer);
                        }
                    } else {
                        // WebSocket is idle and closed.  It is possible that it closed unexpectedly, since disconnect() was not called.  We don't know from here whether the unexpected disconnect was handled properly or not.
                        if (options.warnAboutDisconnectedWebSocketClients) {
                            console.log(`This WebSocketClient (${this.url}) closed earlier without a direct call to disconnect().  Perhaps the remote end disconnected, or the connection timed out.  Hopefully it was handled well.  (It last received data ${idleMinutes} minutes ago.)`);
                            // Assuming this socket has now been abandoned by the app, we should clear our timer to allow GC.
                            clearInterval(this.__checkIdleTimer);
                        }
                    }
                }
            };

            const originalConnect = WebSocketClient.prototype.connect;
            const wrappedConnect = function () {
                this.__lastActivity = Date.now();
                // If this is a reconnect, there may be an existing timer.  Clear it if so.
                clearTimeout(this.__checkIdleTimer);
                this.__checkIdleTimer = setInterval(checkIdle.bind(this), 1000 * 60 * 2);
                return originalConnect.apply(this, arguments);
            };
            WebSocketClient.prototype.connect = wrappedConnect;

            const originalDispatch = WebSocketClient.prototype._dispatch;
            const wrappedDispatch = function () {
                this.__lastActivity = Date.now();
                return originalDispatch.apply(this, arguments);
            };
            WebSocketClient.prototype._dispatch = wrappedDispatch;

            const originalDisconnect = WebSocketClient.prototype.disconnect;
            const wrappedDisconnect = function () {
                clearInterval(this.__checkIdleTimer);
                return originalDisconnect.apply(this, arguments);
            };
            WebSocketClient.prototype.disconnect = wrappedDisconnect;
        }

    },

    /**
     * Replaces all functions in the given object with wrapped copies which perform some logging, but otherwise run as usual.
     *
     * It is very easy to use, just drop this line into the bottom of your file (and check the require path):
     *
     *     require('../modules/debugTools').wrapFunctionsWithLogging(module.exports);
     *
     * @param obj {Object | Array}
     * @returns {Object | Array} the original object
     *
     * Beware: Cannot log arguments if they cannot be JSONed.
     */
    wrapFunctionsWithLogging: function (obj, moduleName) {
        // @todo When there are circular references in the modules, we might get passed an empty obj here.
        //       In such cases we may wish to delay the wrapping.
        //       Unless we can change how we are called, so we are guaranteed to see the finished module.
        const props = Object.keys(obj);
        if (props.length === 0) {
            //console.log("No properties in module " + moduleName);
        }

        for (var key in obj) {
            if (!obj.hasOwnProperty(key)) {
                continue;
            }
            const fn = obj[key];
            if (typeof fn === 'function') {
                (function (originalFn) {
                    // @todo Check if it has already been wrapped
                    const fnName = originalFn.name || key;
                    //console.log("Wrapping %s.%s()", moduleName, fnName);

                    const wrappedFn = function () {
                        const argsArray = [].slice.call(arguments);
                        let argsAsStrings;
                        try {
                            argsAsStrings = argsArray.map(function (arg) {
                                if (arg === undefined) {
                                    return 'undefined';
                                }
                                try {
                                    return JSON.stringify(arg);
                                } catch (e) {
                                    return "[unable_to_stringify]";
                                }
                            });
                        } catch (e) {
                            argsAsStrings = '[failed]';
                        }
                        //var depth = new Error().stack.split('\n').length;
                        const depth = (new Error().stack.match(/\n/g) || []).length;
                        const indentStr = new Array(depth + 1).join('>');
                        let argsString = argsAsStrings.join(', ');
                        if (argsString.length > 500 - 3) {
                            argsString = argsString.substring(0, 500 - 3) + '...';
                        }
                        realConsole.log(indentStr + ' ' + moduleName + ':' + fnName + '(' + argsString + ')');
                        // We could also log the context object (this).
                        return originalFn.apply(this, arguments);
                    };

                    //if (Object.keys(originalFn).length > 0) {
                    //    console.log("Object.keys(%s):", originalFn.name, Object.keys(originalFn));
                    //}

                    // Try to make the wrapped function act as closely as possible to the original function
                    Object.assign(wrappedFn, originalFn);
                    // In Node v4.5.0 these fields are not writable:
                    //wrappedFn.name = originalFn.name;
                    //wrappedFn.length = originalFn.length;
                    // Constructor is supposed to live in the prototype
                    //wrappedFn.constructor = originalFn.constructor;
                    wrappedFn.prototype = originalFn.prototype;
                    // eslint-disable-next-line no-proto
                    wrappedFn.__proto__ = originalFn.__proto__;
                    //wrappedFn.super = originalFn.super;
                    //wrappedFn._super = originalFn._super;

                    // Flag it
                    // wrappedFn._wrappedByDebugTools = true;

                    // Replace the original!
                    obj[key] = wrappedFn;
                }(fn));
            }
        }

        // A constructor/class may have a prototype
        const prototype = obj && obj.prototype;
        if (prototype) {
            // @todo Check if it has already been wrapped
            //console.log("Descending into prototype:", prototype.constructor && prototype.constructor.name);
            debugTools.wrapFunctionsWithLogging(prototype, moduleName + '.prototype');
        }

        // An object/module may have a proto
        const proto = Object.getPrototypeOf(obj);
        if (proto) {
            // @todo Check if it has already been wrapped
            //console.log("Descending into proto:", proto.constructor && proto.constructor.name);
            debugTools.wrapFunctionsWithLogging(proto, moduleName + '.__proto__');
        }

        return obj;
    },

    // Some assistance: http://stackoverflow.com/questions/27948300/override-the-require-function
    // @todo We could try this method to prevent wrapping the same module twice: https://github.com/boblauer/mock-require/blob/21dedf1eb3ccbc3ce2d6c01e38dd888d8df61d89/index.js#L9-L15
    //       That would be preferable to adding our own _wrappedByDebugTools property to each module.
    // @todo We could also try overriding Module._load instead of Module.prototype.require, like they did in mock-require.
    // Proxyquire overrides the require of a given module: https://github.com/thlorenz/proxyquire/blob/master/lib/proxyquire.js
    wrapAllModulesWithLogging: function () {
        // var originalRequire = Module.prototype.require;
        // Module.prototype.require = function (path) {
        //     var module = originalRequire.apply(this, arguments);
        //     if (typeof module === 'object' && !module._wrappedByDebugTools) {
        //         var wrapThis = path.match(/\//) && !path.match(/^\//);
        //         if (wrapThis) {
        //             realConsole.log("* Wrapping module: " + path);
        //             debugTools.wrapFunctionsWithLogging(module, path);
        //             Object.defineProperty(module, '_wrappedByDebugTools', {
        //                 value: true,
        //                 enumerable: false
        //             });
        //         } else {
        //             realConsole.log("  Skipping module: " + path);
        //         }
        //     }
        //     return module;
        // };

        const originalLoader = Module._load;
        const alreadyLoaded = {};
        Module._load = function (request, parent) {
            const fullFilePath = getFullPath(request, parent.filename);

            const module = originalLoader.apply(this, arguments);

            if (typeof module === 'object' && !alreadyLoaded[fullFilePath]) {
                alreadyLoaded[fullFilePath] = true;

                let wrapThis = fullFilePath.match("/");
                if (fullFilePath.match("/node_modules/")) {
                    wrapThis = false;
                }
                if (fullFilePath.match("/schema/")) {
                    wrapThis = false;
                }
                if (fullFilePath.match("server_common/WebSocketService")) {
                    wrapThis = false;
                }
                if (fullFilePath.match(/\/dbproperties\.js$/)) {
                    wrapThis = false;
                }
                if (fullFilePath.match(/\/debugTools\.js$/)) {
                    wrapThis = false;
                }
                if (fullFilePath.match(/\/sunlogger\.js$/)) {
                    wrapThis = false;
                }
                if (fullFilePath.match(/\/promiseDebugging\.js$/)) {
                    wrapThis = false;
                }
                // Was spamming getFunctionName()
                if (fullFilePath.match(/utils\.js$/)) {
                    wrapThis = false;
                }
                // Sometimes we get an error from util.inherits() in winston/lib/winston/transports/http.js
                //if (fullFilePath.match(/http.js$/)) {
                //    wrapThis = false;
                //}
                if (wrapThis) {
                    //realConsole.log("* Wrapping module: " + fullFilePath);
                    //var moduleDisplayName = request.replace(/.*\//, '');
                    // Keep one '/' so we can see the name of the parent folder
                    const moduleDisplayName = '<' + request.replace(/.*\/(.*\/.*)/, '$1') + '>';
                    debugTools.wrapFunctionsWithLogging(module, moduleDisplayName);
                } else {
                    //realConsole.log("  Skipping module: " + fullFilePath);
                }
            }

            return module;
        };
    },

    listFunctionsInObject: function listFunctionsInObject (obj, minimal) {
        for (const prop in obj) {
            const val = obj[prop];
            if (typeof val === 'function') {
                if (minimal) {
                    console.log(':: %s(%s)', prop, val.length);
                }
                else {
                    console.log(':: %s: %s %s', prop, val.toString().split('\n')[0].replace(/\s*\{.*/, ''), val.length);
                }
            }
        }
    },
};

function getProcessNameWithPath () {
    const exeName = process.env.pm_exec_path || process.argv[1] || '';
    return exeName.replace(new RegExp('.*/([^/]*/)'), '$1');
}

var Module = require('module');

const dirname = require('path').dirname;
const join = require('path').join;

// From: https://github.com/boblauer/mock-require/blob/21dedf1eb3ccbc3ce2d6c01e38dd888d8df61d89/index.js
function getFullPath (path, calledFrom) {
    let resolvedPath;
    try {
        resolvedPath = require.resolve(path);
    } catch (e) { }

    const isExternal = /[/\\]node_modules[/\\]/.test(resolvedPath);
    const isSystemModule = resolvedPath === path;
    if (isExternal || isSystemModule) {
        return resolvedPath;
    }

    const isLocalModule = /^\.{1,2}[/\\]/.test(path);
    if (!isLocalModule) {
        return path;
    }

    const localModuleName = join(dirname(calledFrom), path);
    try {
        return Module._resolveFilename(localModuleName);
    } catch (e) {
        if (isModuleNotFoundError(e)) { return localModuleName; }
        else { throw e; }
    }
}

function isModuleNotFoundError (e) {
    return e.code && e.code === 'MODULE_NOT_FOUND';
}

function moduleIsAvailable (path) {
    try {
        require.resolve(path);
        return true;
    } catch (e) {
        return false;
    }
}

module.exports = Object.assign(module.exports, debugTools);