MongoDB Profiler Setup: A Easy Step-by-Step Guide 101

When your database grows, you face a lot of challenges on how to avoid problematic situations that can impede the overall reliability/performance of your database. These tricky scenarios can be handled by taking steps like rewriting difficult queries or analyzing/optimizing database schemas. MongoDB is a reliable document database platform that provides you with wonderful features that can be used to create efficient and reliable databases.

These features of MongoDB include the MongoDB Profiler, Mongostat, Mongotop, etc. In this write-up, we will look at how to set up the MongoDB Profiler to use it to query a database by providing details about a result you want through a query, get query level insights by finding slow queries, setting filters to determine slow queries, specifying the threshold for slow queries, etc. 

What is Profiler in MongoDB?

A database system determines how it handles your query by deciding how to go about it and what physical operation it will perform at any given time. The database profiler collects all information as regards queries that are executed on an individual database instance. When the profiler collects these query details, it does this for the entire instance, ranging from information on the database and the connections on that instance.

MongoDB enable profiling helps to capture and log information about database operations. Profiler in mongodb helps in analyzing and optimizing the performance of queries and operations.

The MongoDB database has an in-built profiler that gives you query-level insights as to why the database chooses a certain operation and it also provides in-depth details of the operations performed such as the queries run, sampling time-slices, etc. The MongoDB profiler also has a feature to record the logs of individual queries which are executed and records all the CRUD operations along with configuration and management controls in logs.

How to Use the MongoDB Profiler?

Detailed information about database commands executed against a running mongod instance is collected by the MongoDB profiler also known as MongoDB query profiler. It writes these collected data to a system.profile collection in each profiled database.

The profiler by default is disabled because it has an effect on database performance and it has a high consumption rate of the memory. It can be enabled on a per-database or per-instance basis at one of the available profiling levels. 

In this section, we will look at how to enable and configure the database profiler by specifying the threshold for slow operations, setting filters to determine profiled operations, checking your profiling level, enable profiling for an entire mongod instance, amongst other things.

Show the Five most recent events

On a database activated with profiling, the mongo shell’s “show profile” helper exhibits the five most recent operations that require a minimum of 1 millisecond for execution. Execute “show profile” command as follows:

show profile

System.profile Collection

The system.profile collection is a limited collection with a size of 1MB. Typically, this size can accommodate thousands of profile documents, but some amount of profiling data per operation may vary among applications. If you find the need to adjust the size of the system.profile collection, follow the steps outlined below.

Modify the Size of system.profile Collection on the Primary

To modify the size of the system.profile collection on the primary, follow these steps;

• Disable profiling
• Drop the existing system.profile collection
• Create a new system.profile collection
• Re-enable profiling

For instance, to create a new system.profile collection sized at 5 MB (5000000 bytes), execute the following sequence of commands in mongosh:

db.setProfilingLevel(0)
db.system.profile.drop()
db.createCollection("system.profile", { capped: true, size: 5000000 })
db.setProfilingLevel(1)

Modify the Size of system.profile Collection on a Secondary

For adjusting the size of the system.profile collection on a secondary, you should stop the secondary and run it as a standalone. Then, follow the steps mentioned above. Once completed, you must restart the standalone as a member of the replica set.

What Information do you get from the system.profiler?

The profiler saves the query in db.system.profile. It can be queried like any other database, so you can find a lot of information about queries directly. 

Along with the query source and the overview of the execution process/ steps, you can get the following information, from db.system.profiler:

1. When the query is executed 
2. How fast did the query get executed 
3. Number of documents checked for the execution of the query
4. Type of plan the query execution plan used 
5. Whether it can be fully utilized and indexed 
6. What kind of  lock occurred during the execution

Enabling and Configuring MongoDB Profiler

The MongoDB profiler is enabled from mongosh or through a driver using the profile command. To enable profiling and set the profiling level, type db.setProfilingLevel() helper in mongosh where you will pass the profiling level you want as a parameter.

There are three profiling levels available in the database profiler, they include:

Level	Description
0	This is the default profiler level set off and it does not collect any data. mongod writes operations longer than the slowOpThresholdMs threshold to its log.
1	This level collects profiling data for slow operations only. Slow operations are regarded as operations that are slower than 100 milliseconds by default though, you can use the slowOpThresholdMs runtime option or the setParameter command to modify your definition of slow operations.
2	This level of the profiler collects profiling data for all the database operations.

The example below enables profiling for all database operations using mongosh.

db.setProfilingLevel(2)

The shell returns a result as seen below.

{ “was” : 0, “slowns” : 100, “ok” : 1 }

The result above contains the previous level indicated by “was”, the slow operation threshold through “slowns”, and the “ok”: 1 key-value pair indicates that the operation is successful. 

How to Specify the Threshold for Slow Operations?

By default, the slow operation threshold is 100 milliseconds though, a database with a profiling level of 1 will log operations slower than 100 milliseconds. Changing the slow operations threshold for the database profiler applies to the entire mongod instance which means when the threshold is altered, it is also changed for all databases on the instance and it affects the profiling subsystem’s slow operation threshold for the entire mongod instance therefore, it is advisable to set the threshold to the highest useful value.

To alter the threshold, you will pass two parameters to the db.setProfilingLevel() helper in mongosh where the first parameter as already seen earlier will be the profiling level and the second one will set the default slow operation threshold for the entire mongod instance as shown in the example below.

db.setProfilingLevel(1, { slowms: 20 })

The example above sets the profiling level at 1 and the slow operation threshold for the mongod instance to 20 milliseconds.

How to Set Filters to Determine MongoDB Profiler Operations?

With the MongoDB profiler, you can set a filter to control which operations are profiled and logged at a given point in time. This is done by using the profile command db.setProfilingLevel() in mongosh as seen below:

db.setProfilingLevel( 2, { filter: { op: "query", millis: { $gt: 2000 } } } )

The example above shows the profiling level of 2 and a query filter of { op: “query”, millis: where only query operations longer than 2 seconds will be logged to the profiler.

How to Unset a filter to Determine MongoDB Profiler Operations?

With the MongoDB profiler, you can unset a filter to clear a profile filter. This is done by using the run profile with the filter: “unset” option.

db.runCommand(
     {
        Profile: 1,
        Filter: “unset”
       }
)

How to Check MongoDB Profiler Level?

To view your MongoDB profiling level, type the following in mongosh.

db.getProfilingStatus()

The shell will return a document that looks like the one below:

{ "was" : 0, "slowms" : 100, "sampleRate" : 1.0, "ok" : 1 }

As stated earlier, the  “was” field shows your current level of profiling,  “slowns”, shows the slow operation threshold by indicating how long it takes an operation to exist in milliseconds before passing through the threshold. In the example above, the “slow” is 100 milliseconds and the “sampleRate” field indicates the percentage of slow operations that should be profiled.

To return only the profiling level of your MongoDB profiler, use the db.getProfilingLevel() helper in the mongosh as indicated below.

db.getProfilingStatus() 

How to Disable MongoDB Profiler?

To disable MongoDB profiler, type db.setProfilingLevel(0) in mongosh as seen below.

db.setProfilingStatus(0)

When the level is set at 0, profiling has automatically been disabled.

How to View MongoDB Profiler Output?

Information about your database operations such as read and write operations, cursor operations, and data-based commands are stored in the database profiler and this information can be viewed by querying the system.profile collection. Additional data can also be added to the query document by using the $comment tag to make it easier to analyze the data gotten from the profiler.

Below is an output of a sample document found in the system.profile collection queried with the command below. Some of the fields found in the output are also described thereafter.

db.system.profile.find().limit(1).pretty()

Output:

{
    "op" : "query",
    "ns" : "mydb.Log",
    "query" : {
        "find" : "Log",
        "filter" : {
            "EMP_ID" : "01778"
        }
    },
    "keysExamined" : 0,
    "docsExamined" : 90022,
    "cursorExhausted" : true,
    "keyUpdates" : 0,
    "writeConflicts" : 0,
    "numYield" : 703,
    "locks" : {
        "Global" : {
            "acquireCount" : {
                "r" : NumberLong(1408)
            }
        },
        "Database" : {
            "acquireCount" : {
                "r" : NumberLong(704)
            }
        },
        "Collection" : {
            "acquireCount" : {
                "r" : NumberLong(704)
            }
        }
    },
    "nreturned" : 60,
    "responseLength" : 17676,
    "protocol" : "op_command",
    "millis" : 40,
    "execStats" : {
        "stage" : "COLLSCAN",
        "filter" : {
            "EMP_ID" : {
                "$eq" : "01778"
            }
        },
        "nReturned" : 60,
        "executionTimeMillisEstimate" : 30,
        "works" : 90024,
        "advanced" : 60,
        "needTime" : 89963,
        "needYield" : 0,
        "saveState" : 703,
        "restoreState" : 703,
        "isEOF" : 1,
        "invalidates" : 0,
        "direction" : "forward",
        "docsExamined" : 90022
    },
    "ts" : ISODate("2018-09-09T07:24:56.487Z"),
    "client" : "127.0.0.1",
    "allUsers" : [ ],
    "user" : ""
}

• Op: This field identifies the type of operation you carried out.
• ns: This field holds the target database and collection name.
• query: This is used to store information about the query and the result. Normally, if the document size is greater than 50KB, the result will be truncated.
• keysExamined: The number of index keys examined by the database to execute the query is found in this field.
• docsExamined: This stores the total number of documents examined by the database.
• nreturned: This field holds the number of documents returned by the query.
• millis: Millis contains the actual time in milliseconds taken by the query to execute the command.
• ts: This field contains the timestamp of the query.

Global and Per-Database Profiling Setting

Profiling settings such as slowms and sampleRate operate on a global scale, affecting all databases within your process.

If configured using the profile command or db.setProfilingLevel() shell helper method, filter settings and profiling level are established at the database level. On the other hand, when specified as command line or configuration file options, these filter settings and profiling levels extend their effect to the entire process.

How to enable Profiling for an Entire mongod Instance

In development and test environments, you can activate database profiling for the entire mongod instance. The profiling level is applicable to all databases given by the mongod instance.

To enable profiling for a MongoDB instance, supply the following parameters to mongod during startup.

mongod –profile 1 –slowms 15 –slowOpSampleRate 0.5

Alternatively, you can set operationProfiling in the configuration file.

This sets the profiling level to one, defines slow operations as those lasting more than 15 milliseconds, and specifies that only half of slow actions should be monitored.

Slowms and slowOpSampleRate also have an impact on the operations logged in the diagnostic log when logLevel is set to zero. Slowms and slowOpSampleRate can also be used to configure diagnostic logging for MongoDB.

Database Profiling and Sharding

Profiling cannot be enabled on a MongoDB instance. To turn on profiling in a sharded cluster, you need to set it up for each mongod instance.

Starting with MongoDB 4.0, you can use the –slowms and slowOpSampleRate options on mongos to set up the diagnostic log for slow operations.

Sample Commands using the MongoDB profiler

The next section contains some sample commands that can be used to query a database to get different information about your data using the MongoDB profiler.

1: To return the 10 most recent log entries in the system.profile collection, run the following query:

db.system.profile.find().limit(10).sort( { ts : -1 } ).pretty()

2: To return queries that are performing large scans on the database, type the following:

db.system.profile.find({docsExamined:{$gt:10000}}).pretty()

3: To return all operations except command operations ($cmd), run a query like the one below:

db.system.profile.find( { op: { $ne : 'command' } } ).pretty()

4: To return all the operations for which some documents were moved, run the query below:

db.system.profile.find({moved:true}).pretty()

5: To return operations for a particular collection, type the query similar to the one below and it will return operations found in the mydb database’s test collection:

db.system.profile.find( { ns : 'mydb.test' } ).pretty()

6: To return operations slower than 5 milliseconds, run a query similar to the following:

db.system.profile.find( { millis : { $gt : 5 } } ).pretty()

7: To return the top 10 slowest aggregation/command queries, run a query similar to the one below:

db.system.profile.find({op: {$eq: “command” }}).sort({millis:-1}).limit(10).pretty();

8: To return information from a certain time range, run the following:

db.system.profile.find({
  ts : {
    $gt: new ISODate("2012-12-09T03:00:00Z"),
    $lt: new ISODate("2012-12-09T03:40:00Z")
  }
}).pretty()

9: To return the maximum and average time taken by each type of operation using aggregation, type the following command:

db.system.profile.aggregate(
{ $group : { 
   _id :"$op", 
   count:{$sum:1},
   "max_time":{$max:"$millis"},
   "avg_time":{$avg:"$millis"}
}}).pretty()

10: To return the maximum and average time taken by queries in each database using aggregation, run the query:

db.system.profile.aggregate(
{ $group : {
  _id :"$ns",
  count:{$sum:1}, 
  "max_time":{$max:"$millis"}, 
  "avg_time":{$avg:"$millis"}  
}}.pretty()

11: To return Sorted Queries by when they were recorded, run the following query:

db.system.profile.find({
"command.pipeline": { $exists: true }
}, {
"command.pipeline":1
}).sort({$natural:-1}).pretty();

12: To return all queries with a particular comment, type the following query:

db.Customers.find({
"Name.Last Name" : "Johnston"
}, {
"_id" : NumberInt(0),
"Full Name" : NumberInt(1)
}).sort({
"Name.First Name" : NumberInt(1)
}).comment( "Find all Johnstons and display their full names alphabetically" );

//display all queries with comments
db.system.profile.find({ "query.comment": {$exists: true} }, { query: 1 }).pretty()

What Causes MongoDB Queries to Slow Down?

You just need to know what a slow query is, so you need to specify what you consider to be slow, that is a millisecond criterion. Of course, you can save all queries and aggregates and select only those queries that match your criteria. As seen above you can use the following command to get all those queries that took more than 20ms.

 // Find something that took more than 20ms
 db.system.profile.find ({"millis": {$ gt: 20}}) 

You will find that there is too much “noise” in a heavily loaded system. In this case, it is much better to use profiling level 1. This saves only slow queries. There may be queries that are executed very often, for example, a Website Authentication routine. It takes a reasonable amount of time, but it is inefficient. We need a measure of cumulative time over a period of time, so we need full profiling at level 2. However, it often makes sense to have the ability to save only slow queries. Here, choose to collect only data for operations that take longer than the slowms reference value. At the same time, you can set slowms to 30ms.

Considerations

The following factors should be considered while setting up a MongoDB Profiler

1. Security

Profile data may contain sensitive information, such as the substance of database searches. Ensure that disclosing this data to Atlas is in line with your information security policies.

2. Data Analysis Limitations

The Query Profiler can show over 10,000 recent operations or 10 MB of the most recent logs. Afterward, the Query Profiler won’t show new operations for 24 hours.

3. Data Display Limitations

Atlas shows fewer than 10,000 observations in the Profiler illustrations.

Log data is handled in batches. Data can be delayed for as long as five minutes in real time.

4. Log Quantity

If a cluster experiences a spike in activity and generates a significant number of log messages, Atlas may temporarily stop collecting and storing new logs.

Conclusion

In this piece, you have been introduced to MongoDB and given insights about its Database Profiler to enable you to handle issues of your database by getting helpful information from them through a query command.

It also explained how the MongoDB profiler can be enabled/disabled, how to check the MongoDB profiler level, how to view the database output, explaining the content of the output with an example, etc. Having gone through this article, you should be more efficient in querying your database to get useful information.

MongoDB is a trusted source that a lot of companies use as it provides many benefits but transferring data from it into a data warehouse is a hectic task. The Automated data pipeline helps in solving this issue and this is where Hevo comes into the picture. Hevo is the only real-time ELT No-code Data Pipeline platform that cost-effectively automates data pipelines that are flexible to your needs.

Try a 14-day free trial and experience the feature-rich Hevo suite firsthand. Also, check out our unbeatable pricing to choose the best plan for your organization.

FAQs