createIndex on system.profile collection

Hello,

During a recent performance incident we noticed slow COLLSCAN queries against the system.profile collection in mongod.log. These originated from a mongodb_exporter that is used to integrate with prometheus for monitoring:

{"t":{"$date":"2024-05-15T10:39:01.549Z"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn860","msg":"Slow query","attr":{"type":"command","ns":"XXX.system.profile","appName":"mongodb_exporter","command":{"aggregate":"system.profile","pipeline":[{"$match":{"ts":{"$gte":{"$date":"2024-05-15T10:38:30.031Z"}}}},{"$group":{"_id":1,"n":{"$sum":1}}}],"cursor":{},"lsid":{"id":{"$uuid":"ec5520a7-3fa8-42e9-bf06-d81de4a17e0e"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1715769540,"i":4}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"XXX","$readPreference":{"mode":"primaryPreferred"}},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":20873,"cursorExhausted":true,"numYields":112,"nreturned":0,"queryHash":"C8EF8025","planCacheKey":"4C421733","reslen":241,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":114}},"Global":{"acquireCount":{"r":114}},"Mutex":{"acquireCount":{"r":2}}},"readConcern":{"level":"local","provenance":"implicitDefault"},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"customDefault"},"storage":{"data":{"bytesRead":1075094307,"timeReadingMicros":1477518}},"remote":"127.0.0.1:50248","protocol":"op_msg","durationMillis":1517}}

We can see that the underlying query is uses $gte on the ts field.
Inspection of the system.profile collection shows that there no indexes present (even no _id one and the documents therein have no _id field).

Furthermore we cannot create any indexes in this collection:

db.getCollection("system.profile").createIndex({ts:1})
{
        "ok" : 0,
        "errmsg" : "cannot write to admin.system.profile",
        "code" : 73,
        "codeName" : "InvalidNamespace",
        "$clusterTime" : {
                "clusterTime" : Timestamp(1716476756, 71),
                "signature" : {
                        "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
                        "keyId" : NumberLong(0)
                }
        },
        "operationTime" : Timestamp(1716476756, 71)
}

Is it possible to create indexes on this collection by some other means to minimise the impact of these queries? Metrics are gathered at frequent intervals. Appreciate one way to reduce the impact is to reduce the size of the collection (this one is historically “large” at 1Gb in our deployments).

Some example queries including ts are in the documentation: https://www.mongodb.com/docs/manual/tutorial/manage-the-database-profiler/#std-label-database-profiling-example-queries.

Server version 5.0.26
Any help is much appreciated.

Thanks
Jason King

Apologies for the bad formatting in the original post :slightly_frowning_face:.
There’s an extra quote (and there’s no preview/edit option) - if a moderator could remove it that would be great :slight_smile:

Hello, welcome to the MongoDB community.

By default, system.profile is only created when profiling is activated, however for production environments this can cause performance problems, as mentioned in this documentation

The collection is time capped and contains around 1MB when created. As you have a collection much higher than normal (1024 times larger).

I recommend reducing the size of the collection so as not to impact the process and even review the need for continuous profiling in a production environment.

If you need to have a history of this, I think it’s best to collect the data with Prometheus and store it in a datasource to generate metrics and graphs.

Hi Samuel, Thank you for your reply.
Yes I now agree! Plan is to reduce the size significantly to a value much closer to the default. We can use prometheus or logs for historical analysis; plus have the option to temporarily increase again should we need to. We are capturing operations over 1s which isn’t too noisy:

"operationProfiling": {
  "mode": "slowOp",
  "slowOpThresholdMs": 1000
}

Will follow the documented procedure here to make the change to the capped collection size.

Thanks for your assistance.
Jason King

1 Like

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.