208

The question is as basic as it is simple... How do you log all queries in a "tail"able log file in mongodb?

I have tried:

  • setting the profiling level
  • setting the slow ms parameter starting
  • mongod with the -vv option

The /var/log/mongodb/mongodb.log keeps showing just the current number of active connections...

João Rocha da Silva
  • 4,259
  • 4
  • 26
  • 35

16 Answers16

307

You can log all queries:

$ mongo
MongoDB shell version: 2.4.9
connecting to: test
> use myDb
switched to db myDb
> db.getProfilingLevel()
0
> db.setProfilingLevel(2)
{ "was" : 0, "slowms" : 1, "ok" : 1 }
> db.getProfilingLevel()
2
> db.system.profile.find().pretty()

Source: http://docs.mongodb.org/manual/reference/method/db.setProfilingLevel/

db.setProfilingLevel(2) means "log all operations".

Stefan van den Akker
  • 6,661
  • 7
  • 48
  • 63
Kristóf Dombi
  • 3,927
  • 3
  • 18
  • 14
  • 6
    At a glance, it looks like this is a better answer than the accepted answer. – Ehtesh Choudhury Nov 10 '14 at 22:04
  • 3
    Not better, given that the questions asks for a tailable log file, but definitely useful, in cases where you don't have access to the log files, only the mongo shell, like the one that brought me here :) – inolasco Feb 20 '15 at 23:30
  • 17
    I tried setting the profiling level to 2 but I also needed to set the second parameter to -1, like `db.setProfilingLevel(2,-1)` – andresigualada Apr 12 '16 at 10:42
  • 5
    For those interested where the logs go, the doc states: mongod writes the output of the database profiler to the `system.profile` collection. – totymedli Jun 17 '16 at 09:13
  • 6
    `db.system.profile.find().pretty()` gives nothing for me – node_saini Jan 06 '17 at 09:19
  • 1
    @node_saini Try `db.setProfilingLevel(2, 1)` – Ashish Mar 09 '17 at 06:46
  • when using username and password: `mongo DATABASENAME -u DATABASEUSER -p DATABASEPASSWORD --authenticationDatabase admin` – oceanBT Oct 15 '20 at 14:22
91

I ended up solving this by starting mongod like this (hammered and ugly, yeah... but works for development environment):

mongod --profile=1 --slowms=1 &

This enables profiling and sets the threshold for "slow queries" as 1ms, causing all queries to be logged as "slow queries" to the file:

/var/log/mongodb/mongodb.log

Now I get continuous log outputs using the command:

tail -f /var/log/mongodb/mongodb.log

An example log:

Mon Mar  4 15:02:55 [conn1] query dendro.quads query: { graph: "u:http://example.org/people" } ntoreturn:0 ntoskip:0 nscanned:6 keyUpdates:0 locks(micros) r:73163 nreturned:6 reslen:9884 88ms
João Rocha da Silva
  • 4,259
  • 4
  • 26
  • 35
  • 6
    Should this be equivalent to adding `profile=1` and `slowms=1` lines in `/etc/mongodb.conf`? – Andrew Magee Feb 10 '14 at 07:47
  • I couldn't find /var/log/mongodb/mongodb.log but it was logging in the console, which I needed. Thanks – auhuman Mar 19 '14 at 18:46
  • 5
    You can just add `--profile=2` to `/etc/mongodb.conf` according to official Mongo docs, any all operations will be logged. – toske Jul 30 '15 at 12:04
  • 1
    @auhuman Where to write "tail -f /var/log/mongodb/mongodb.log" command?? – Half Blood Prince May 07 '16 at 10:40
  • 7
    No need to restart you can simply use `db.setProfilingLevel(level,slowms)`. For eg: `db.setProfilingLevel(2,1)` will set level to be 2 and slow query threshold to be 1ms. – Abhishek Gupta Jun 08 '16 at 07:06
  • I don't think adding "profile=1" to /etc/mongod.conf works anymore, believe that works in Mongo < 2.6. Config now uses YAML format. – Carlton Sep 19 '17 at 10:49
  • You can add `operationProfiling:` with the two values `mode: slowOp` `slowOpThresholdMs: 0` below that to the YAML version of mongod.conf. – garlon4 Feb 19 '18 at 19:27
  • Can someone explain the structure MongoDB follows when logging the profiler documents in the log message? For example, the field responseLength in the profiler document is written as resLen in MongoDB's log (as mentioned in https://docs.mongodb.com/manual/reference/database-profiler/#system.profile.responseLength ). Want to know how and where this translation takes place. – Soban Soundararajan Sep 12 '19 at 11:45
37

Because its google first answer ...
For version 3

$ mongo
MongoDB shell version: 3.0.2
connecting to: test
> use myDb
switched to db
> db.setLogLevel(1)

http://docs.mongodb.org/manual/reference/method/db.setLogLevel/

barak
  • 869
  • 1
  • 11
  • 15
29

MongoDB has a sophisticated feature of profiling. The logging happens in system.profile collection. The logs can be seen from:

db.system.profile.find()

There are 3 logging levels (source):

  • Level 0 - the profiler is off, does not collect any data. mongod always writes operations longer than the slowOpThresholdMs threshold to its log. This is the default profiler level.
  • Level 1 - collects profiling data for slow operations only. By default slow operations are those slower than 100 milliseconds. You can modify the threshold for “slow” operations with the slowOpThresholdMs runtime option or the setParameter command. See the Specify the Threshold for Slow Operations section for more information.
  • Level 2 - collects profiling data for all database operations.

To see what profiling level the database is running in, use

db.getProfilingLevel()

and to see the status

db.getProfilingStatus()

To change the profiling status, use the command

db.setProfilingLevel(level, milliseconds)

Where level refers to the profiling level and milliseconds is the ms of which duration the queries needs to be logged. To turn off the logging, use

db.setProfilingLevel(0)

The query to look in the system profile collection for all queries that took longer than one second, ordered by timestamp descending will be

db.system.profile.find( { millis : { $gt:1000 } } ).sort( { ts : -1 } )
Giacomo1968
  • 25,759
  • 11
  • 71
  • 103
Zameer Ansari
  • 28,977
  • 24
  • 140
  • 219
  • 1
    According to the documentation, **Loglevel 0** does **not** mean "no logging" but it logs slow queries: "the profiler is off, does not collect any data. mongod always writes operations longer than the slowOpThresholdMs threshold to its log." src: https://docs.mongodb.com/v3.2/tutorial/manage-the-database-profiler/#profiling-levels – kayn Oct 31 '16 at 10:04
24

I made a command line tool to activate the profiler activity and see the logs in a "tail"able way --> "mongotail":

$ mongotail MYDATABASE
2020-02-24 19:17:01.194 QUERY  [Company] : {"_id": ObjectId("548b164144ae122dc430376b")}. 1 returned.
2020-02-24 19:17:01.195 QUERY  [User] : {"_id": ObjectId("549048806b5d3db78cf6f654")}. 1 returned.
2020-02-24 19:17:01.196 UPDATE [Activation] : {"_id": "AB524"}, {"_id": "AB524", "code": "f2cbad0c"}. 1 updated.
2020-02-24 19:17:10.729 COUNT  [User] : {"active": {"$exists": true}, "firstName": {"$regex": "mac"}}
...

But the more interesting feature (also like tail) is to see the changes in "real time" with the -f option, and occasionally filter the result with grep to find a particular operation.

See documentation and installation instructions in: https://github.com/mrsarm/mongotail

(also runnable from Docker, specially if you want to execute it from Windows https://hub.docker.com/r/mrsarm/mongotail)

Mariano Ruiz
  • 4,314
  • 2
  • 38
  • 34
  • 2
    this is the most complete response to the OP. esp. regarding the 'tail-able' requirement. – Luke W Dec 01 '16 at 15:12
17

if you want the queries to be logged to mongodb log file, you have to set both the log level and the profiling, like for example:

db.setLogLevel(1)
db.setProfilingLevel(2)

(see https://docs.mongodb.com/manual/reference/method/db.setLogLevel)

Setting only the profiling would not have the queries logged to file, so you can only get it from

db.system.profile.find().pretty()
DariusNica
  • 463
  • 6
  • 14
11

Once profiling level is set using db.setProfilingLevel(2).

The below command will print the last executed query.
You may change the limit(5) as well to see less/more queries.
$nin - will filter out profile and indexes queries
Also, use the query projection {'query':1} for only viewing query field

db.system.profile.find(
{ 
    ns: { 
        $nin : ['meteor.system.profile','meteor.system.indexes']
    }
} 
).limit(5).sort( { ts : -1 } ).pretty()

Logs with only query projection

db.system.profile.find(
{ 
    ns: { 
        $nin : ['meteor.system.profile','meteor.system.indexes']
    }
},
{'query':1}
).limit(5).sort( { ts : -1 } ).pretty()
Faiz Mohamed Haneef
  • 3,418
  • 4
  • 31
  • 41
7

The profiler data is written to a collection in your DB, not to file. See http://docs.mongodb.org/manual/tutorial/manage-the-database-profiler/

I would recommend using 10gen's MMS service, and feed development profiler data there, where you can filter and sort it in the UI.

Hans N. Hjort
  • 851
  • 7
  • 19
  • 1
    Yeah, after activating level 2 profiling, a collection is added to the database. However, having to reload a gui or running a command everytime I perform debugging is a PITA at the end of the day... Thats why i wanted a tailable log file. – João Rocha da Silva Mar 04 '13 at 14:59
4

I think that while not elegant, the oplog could be partially used for this purpose: it logs all the writes - but not the reads...

You have to enable replicatoon, if I'm right. The information is from this answer from this question: How to listen for changes to a MongoDB collection?

Community
  • 1
  • 1
ppeterka
  • 20,583
  • 6
  • 63
  • 78
4

Setting profilinglevel to 2 is another option to log all queries.

Shnkc
  • 2,108
  • 1
  • 27
  • 35
4
db.setProfilingLevel(2,-1)

This worked! it logged all query info in mongod log file

djoker
  • 116
  • 1
  • 5
3

I recommend checking out mongosniff. This can tool can do everything you want and more. Especially it can help diagnose issues with larger scale mongo systems and how queries are being routed and where they are coming from since it works by listening to your network interface for all mongo related communications.

http://docs.mongodb.org/v2.2/reference/mongosniff/

Daniel Williams
  • 8,673
  • 4
  • 36
  • 47
  • According to that page, it only works in UNIX enviros, and i don't have it in my bin dir in windows. Any recommended windows equiv? – propagated Apr 10 '14 at 19:13
  • Are you running on a remote windows server (azure cloud, etc) or locally on your pc? If it's all locally wireshark will be more than sufficient. To install it on windows you will need to build mongosniff.exe which is a bit undocumented. You follow the linux instructions but you need to install the development version of winpcap. – Daniel Williams Apr 11 '14 at 16:52
  • Thanks for the reply. I ended up able to get the information i needed out of the mongo profiler, but i'll keep wireshark in my pocket if something more serious arises again. – propagated Apr 11 '14 at 19:34
2
db.adminCommand( { getLog: "*" } )

Then

db.adminCommand( { getLog : "global" } )
4b0
  • 21,981
  • 30
  • 95
  • 142
HareesH P
  • 21
  • 1
  • 5
    Welcome to Stack Overflow! While this code may solve the question, [including an explanation](https://meta.stackexchange.com/questions/114762/explaining-entirely-code-based-answers) really helps to improve the quality of your post. – 4b0 May 24 '19 at 06:45
1

I wrote a script that will print out the system.profile log in real time as queries come in. You need to enable logging first as stated in other answers. I needed this because I'm using Windows Subsystem for Linux, for which tail still doesn't work.

https://github.com/dtruel/mongo-live-logger

user3413723
  • 11,147
  • 6
  • 55
  • 64
1

This was asked a long time ago but this may still help someone:

MongoDB profiler logs all the queries in the capped collection system.profile. See this: database profiler

  1. Start mongod instance with --profile=2 option that enables logging all queries OR if mongod instances is already running, from mongoshell, run db.setProfilingLevel(2) after selecting database. (it can be verified by db.getProfilingLevel(), which should return 2)
  2. After this, I have created a script which utilises mongodb's tailable cursor to tail this system.profile collection and write the entries in a file. To view the logs I just need to tail it:tail -f ../logs/mongologs.txt. This script can be started in background and it will log all the operation on the db in the file.

My code for tailable cursor for the system.profile collection is in nodejs; it logs all the operations along with queries happening in every collection of MyDb:

const MongoClient = require('mongodb').MongoClient;
const assert = require('assert');
const fs = require('fs');
const file = '../logs/mongologs'
// Connection URL
const url = 'mongodb://localhost:27017';

// Database Name
const dbName = 'MyDb';
//Mongodb connection

MongoClient.connect(url, function (err, client) {
   assert.equal(null, err);
   const db = client.db(dbName);
   listen(db, {})
});

function listen(db, conditions) {
var filter = { ns: { $ne: 'MyDb.system.profile' } }; //filter for query
//e.g. if we need to log only insert queries, use {op:'insert'}
//e.g. if we need to log operation on only 'MyCollection' collection, use {ns: 'MyDb.MyCollection'}
//we can give a lot of filters, print and check the 'document' variable below

// set MongoDB cursor options
var cursorOptions = {
    tailable: true,
    awaitdata: true,
    numberOfRetries: -1
};

// create stream and listen
var stream = db.collection('system.profile').find(filter, cursorOptions).stream();

// call the callback
stream.on('data', function (document) {
    //this will run on every operation/query done on our database
    //print 'document' to check the keys based on which we can filter
    //delete data which we dont need in our log file

    delete document.execStats;
    delete document.keysExamined;
    //-----
    //-----

    //append the log generated in our log file which can be tailed from command line
    fs.appendFile(file, JSON.stringify(document) + '\n', function (err) {
        if (err) (console.log('err'))
    })

});

}

For tailable cursor in python using pymongo, refer the following code which filters for MyCollection and only insert operation:

import pymongo
import time
client = pymongo.MongoClient()
oplog = client.MyDb.system.profile
first = oplog.find().sort('$natural', pymongo.ASCENDING).limit(-1).next()

ts = first['ts']
while True:
    cursor = oplog.find({'ts': {'$gt': ts}, 'ns': 'MyDb.MyCollection', 'op': 'insert'},
                        cursor_type=pymongo.CursorType.TAILABLE_AWAIT)
    while cursor.alive:
        for doc in cursor:
            ts = doc['ts']
            print(doc)
            print('\n')
        time.sleep(1)

Note: Tailable cursor only works with capped collections. It cannot be used to log operations on a collection directly, instead use filter: 'ns': 'MyDb.MyCollection'

Note: I understand that the above nodejs and python code may not be of much help for some. I have just provided the codes for reference.

Use this link to find documentation for tailable cursor in your languarge/driver choice Mongodb Drivers

Another feature that i have added after this logrotate.

Ankit
  • 143
  • 1
  • 8
0

Try out this package to tail all the queries (without oplog operations): https://www.npmjs.com/package/mongo-tail-queries

(Disclaimer: I wrote this package exactly for this need)

dmchk
  • 608
  • 6
  • 8