How to get print output for debugging map/reduce in Mongoid?

Question

I'm writing a map/reduce operation with Mongoid 3.0. I'm trying to use the print statement to debug the JS functions. This is a troubleshooting suggestion from the MongoDB docs, e.g.:

reduce = %Q{
   function(user_id, timestamps) {
      var max = 0;
      timestamps.forEach(function(t) {
        var diff = t.started_at - t.attempted_at;
        if (diff > max) { max = diff; }
      });
      print(user_id + ', ' + max);
      return max;
    };
  }

 MyCollection.all.map_reduce(map, reduce).to_a

Unfortunately the output from the print statement shows up neither on the console nor on the log--it seems that this is suppressed somewhere between the DB, the driver, Moped or any of the intervening layers. Is there a way to turn this on?

Bonnette

Answer 1

Per the poster's comment, the first step is to make sure you are looking at the mongod server log. The easiest way to do this locally is by visiting the little-known HTTP interface to mongod: http://localhost:28017. This will work even if the server is not installed in its default location and, therefore, the log will not be in the default OS-specific location, e.g, /usr/local/var/log/mongodb/mongo.log on Mac OS X. See the docs for how to access this in non-standard deployment environments.

If that doesn't solve your problem, you'll have to go deeper into debugging MongoDB M/R, which is tricky for several reasons:

1. M/R jobs execute in a JS scope that is isolated from the rest of the DB
2. M/R jobs cannot write to anything other than the M/R output documents
3. The logger in MongoDB has discretion over what to emit to the logging stream

Here are my suggestions based on our extensive use of Mongo M/R in production:

Increase the logging level

Suddenly, some of the previously invisible print output will show up. Do it one level at a time until you start seeing it.

use admin
db.runCommand( { setParameter: 1, logLevel: 2 } )

Log levels vary from 0 to 5. See setParameter. You can also do this at server startup with -v, -vv, ..., -vvvvv.

Increase the profiling level to max (2)

I've found this useful, especially when combined with a high log level as it provides data exhaust (the profiling collection) that can be programmatically inspected. See the docs.

If you are running a very big M/R job, this may negatively affect performance.

Piggyback debug output through M/R

The idea is simple: add an array of objects with whatever debugging info you need, say in the _debug field, to all emitted documents and filter + concatenate as you see fit in the reduce phase. This way, the _debug arrays will end up in your output collection. You can even index them if you want to quickly find a particular problem.

Hope this helps. Good luck!

Consentient

Thanks for these suggestions. As it turns out, the answer is simple. I found a hint on the Mongoid Google Group. See my own answer below. – Bonnette

@WolframArnold Oh, I thought you were already looking at the mongod log. – Consentient

sorry for the confusion. I was talking about the Rails log and Rails console. I'm using the Mongoid document adapter. Thanks for the effort. – Bonnette

I use Mongoid also. Lots of voodoo there, esp with the new driver. I updated my answer with info on how to see the log through the browser in an OS and installation-independent manner as well as for remote servers that have this enabled, e.g., in a private network. Normal file access to the logs may not work there. – Consentient

Ok, I'll give you the credit for the remote situation. Although the local file access that I came up with was what solved my immediate problem. Thanks for the detail. – Bonnette

Answer 2

It turns out the print statements logs to the MongoDB server log. On OSX, that is /usr/local/var/log/mongodb/mongo.log

Bonnette

This worked for me tail -f /usr/local/var/log/mongodb/output.log – Essayist

combining this with a pipe and a grep helped me filter out the noise! thx! $ tail -f /usr/local/var/log/mongodb/mongo.log | grep 'mystuff' – Goodyear

I am using OSX too but my log file is empty. Do I need to switch on anything in config file etc.? – Electrode