How can I wrap sails-mongo db methods for profiling?

Question

I'm trying to setup a sails hook with miniprofiler to help profile mongo usage. I'm struggling for how to wrap the db methods in a function that will execute the profile. I'm trying to do this via a user hook:

setupMiniprofilerMongo(req, res, next) {
  const adapter = sails.hooks.orm.datastores.default.adapter;
  const adapterPrototype = Object.getPrototypeOf(adapter);
  const originalMethod = adapter.adapter.find;
  methodPrototype.find = function profiledMongoCommand(connectionName, collectionName, options, cb) {
    sails.log.info(`${collectionName}.find`);
    return originalMethod.call(adapter, connectionName, collectionName, options, cb);
  };
}

That causes the following error to be thrown:

TypeError: Cannot read property 'collections' of undefined
    at Object.module.exports.adapter.find (/Users/jgeurts/dev/platform/node_modules/sails-mongo/lib/adapter.js:349:40)
    at Object.profiledMongoCommand [as find] (/Users/jgeurts/dev/platform/config/http.js:234:37)

Any help would be appreciated. I tried to wrap the methods on mongodb package, but that doesn't seem to work either. :/

At which layer do you want the profiler to hook in? I think it makes difference whether you hook in at application level or inside sails-mongo or even inside native mongo nodejs driver. And your error sails collections of undefined however there is no collections usage in the code you provided. — DarkLeafyGreen, Sep 14 '16 at 07:28
@zabware For this need, I'm indifferent if I'm hooking to sails-mongo or native mongo. I'm mainly looking to profile how long the query took and less about how long waterline took to parse the results. The `collections` object is defined inside the adapter closure. Unfortunately, it doesn't appear to have an easy accessor — Jim Geurts, Sep 14 '16 at 19:29
If I could profile the raw mongodb calls, that would be ideal. That would account for cases where native queries are used as well as waterline syntax. Getting at the mongodb adapter instance through the waterline object graph is not clear to me, though — Jim Geurts, Sep 14 '16 at 21:06

Jim Geurts · Accepted Answer · 2016-09-20T14:59:18.470

I got this working by wrapping waterline query methods. There is room for improvement, though.

setupMiniprofilerWaterline(req, res, next) {
  const dbOperations = [
    'count',
    'create',
    'createEach',
    'define',
    'describe',
    'destroy',
    'drop',
    'find',
    'join',
    //        'native',
    //        'registerConnection',
    'update',
  ];

  const waterlineMethodByModels = {};
  const miniprofilerWaterline = () => {
    return {
      name: 'mongodb',
      handler(req, res, next) {

        if (!req.miniprofiler || !req.miniprofiler.enabled) {
          return next();
        }

        const profiler = req.miniprofiler;

        for (const modelName of _.keys(sails.models)) {
          for (const dbOperation of dbOperations) {
            const model = sails.models[modelName];
            if (!model[dbOperation]) {
              continue;
            }

            if (!waterlineMethodByModels[modelName]) {
              waterlineMethodByModels[modelName] = {};
            }

            // Prevent wrapping a method more than once
            if (waterlineMethodByModels[modelName][dbOperation]) {
              continue;
            }

            waterlineMethodByModels[modelName][dbOperation] = true;

            const originalMethod = model[dbOperation];

            model[dbOperation] = function profiledMongoCommand(...args) {
              const query = args && args.length ? args[0] : '';
              const lastArg = args && args.length ? args[args.length - 1] : null;
              const modelAndMethod = `${modelName}.${dbOperation}`;

              if (lastArg && typeof lastArg === 'function') {
                sails.log.debug(`mongo::${modelAndMethod}  - ${JSON.stringify(query)}`);
                const callback = args.pop();

                const timing = profiler.startTimeQuery('mongodb', query ? JSON.stringify(query || '') : '');
                // In general, the callstack is kind of useless to us for these profiles
                // The model/db method is more useful in the miniprofiler UI
                timing.callStack = `\n\nMethod: ${modelAndMethod}`;

                return originalMethod.call(this, ...args, function profiledResult(...results) {
                  profiler.stopTimeQuery(timing);
                  callback(...results);
                });
              }

              const methodResult = originalMethod.call(this, ...args);
              const methodResultPrototype = Object.getPrototypeOf(methodResult);
              const isDeferred = !!methodResultPrototype.exec;
              // If methodResult is a Deferred object type, then the query method will be profiled above when the deferred is executed (with a callback)
              // So we only care to log this if the methodResult is not a deferred object
              if (!isDeferred) {
                sails.log.warn(`Was not able to profile mongo::${modelAndMethod}. Maybe its a promise? query: ${JSON.stringify(query)}`);
              }

              return methodResult;
            };
          }
        }

        next();
      },
    };
  };

  miniprofiler.express.for(miniprofilerWaterline())(req, res, next);
},

The code is available as miniprofiler-waterline if you want to contribute/use it in your own projects

How can I wrap sails-mongo db methods for profiling?

1 Answers1