Set additional logging and tracing in mongodb

logLevel Parameter

To set logging on an ad hoc basis, the parameter can be set in the admin database:

--Current log level:
use admin;
db.runCommand({ getParameter: 1, logLevel: 1 })


Logging can be set between 0 and 5, with 5 being the most verbose logging:

--Set log level to 3
use admin;
db.runCommand( { setParameter: 1, logLevel: 3 } )

LogLevel can also be set at instance startup in the mongod.conf under the systemLog.verbosity parameter:

For more details – http://docs.mongodb.org/manual/reference/configuration-options/#systemLog.verbosity

Database Profiling

The database profiler collects fine grained data about MongoDB write operations, cursors, database commands on a running mongod instance. You can enable profiling on a per-database or per-instance basis. The database profiling is also configurable when enabling profiling

--get the tracing level and current slow ops threshold
db.getProfilingStatus()

--set the profiling level to 2
db.setProfilingLevel(2)


See here for full profiling details – http://docs.mongodb.org/manual/tutorial/manage-the-database-profiler/

// last few entries
show profile                                                     
 
// sort by natural order (time in)
db.system.profile.find({}).sort({$natural:-1})
 
// sort by slow queries first
db.system.profile.find({}).sort({$millis:-1})Alimit(10);
 
// anything > 20ms                  
db.system.profile.find({"millis":{$gt:20}})
 
// single coll order by response time                      
db.system.profile.find({"ns":"test.foo"}).sort({"millis":-1})
 
// regular expression on namespace
db.system.profile.find( { "ns": /test.foo/ } ).sort({millis:-1,$ts:-1})
 
// anything thats moved    
db.system.profile.find({"moved":true})
 
// large scans                           
db.system.profile.find({"nscanned":{$gt:10000}})
 
// anything doing range or full scans                 
db.system.profile.find({"nreturned":{$gt:1}})

Aggregation framework queries:

--response time by operation type
db.system.profile.aggregate(
{ $group : { 
   _id :"$op", 
   count:{$sum:1},
   "max response time":{$max:"$millis"},
   "avg response time":{$avg:"$millis"}
}});
 
--slowest by namespace
db.system.profile.aggregate(
{ $group : {
  _id :"$ns",
  count:{$sum:1}, 
  "max response time":{$max:"$millis"}, 
  "avg response time":{$avg:"$millis"}  
}},
{$sort: {
 "max response time":-1}
}); 
 
--slowest by client
db.system.profile.aggregate(
{$group : { 
  _id :"$client", 
  count:{$sum:1}, 
  "max response time":{$max:"$millis"}, 
  "avg response time":{$avg:"$millis"}  
}},
{$sort: { 
  "max response time":-1} 
});

Advertisements

Trace Session for Schema on Login

The following trigger starts a session trace whenever a session for a particular schema logs into the database:

CREATE OR REPLACE TRIGGER ON_MY_SCHEMA_LOGIN
AFTER LOGON ON DATABASE
WHEN ( USER = 'MySCHEMA' )
BEGIN
execute immediate 'alter session set events ''10046 trace name context forever, level 12''';
EXCEPTION
WHEN OTHERS THEN
NULL;
END;

Level definitions:

For methods that require tracing levels, the following are valid values:

  • 0 – No trace. Like switching sql_trace off.

  • 2 – The equivalent of regular sql_trace.

  • 4 – The same as 2, but with the addition of bind variable values.

  • 8 – The same as 2, but with the addition of wait events.

  • 12 – The same as 2, but with both bind variable values and wait events.

  • To turn off session level traces that are running:

    ALTER SESSION SET EVENTS '10046 trace name context off';