[SERVER-13053] createIndexes command should be explicitly logged Created: 05/Mar/14  Updated: 11/Jul/16  Resolved: 21/Mar/14

Status: Closed
Project: Core Server
Component/s: Index Maintenance
Affects Version/s: 2.6.0-rc0
Fix Version/s: 2.6.0-rc2

Type: Bug Priority: Major - P3
Reporter: Bernie Hackett Assignee: Eric Milkie
Resolution: Done Votes: 1
Labels: 26qa
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
is related to SERVER-12926 Insert write commands on documents >=... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

When attempting to call createIndexes against a 2.4.x mongod I see the following in the log:

Wed Mar  5 11:26:15.568 [conn1] run command foo.$cmd { createIndexes: "bar", indexes: [ { name: "a_1", key: { a: 1 } } ] }

Calling createIndexes against 2.6rc0 results in a log message like this:

2014-03-05T11:29:36.272-0800 [conn1] command foo.$cmd command: { v: 1, key: { b: 1 }, name: "b_1", ns: "foo.bar" } keyUpdates:0 numYields:0 locks(micros) r:30 w:406 reslen:113 0ms

The createIndexes: "bar" part should really be in the 2.6 log as well.



 Comments   
Comment by Githook User [ 21/Mar/14 ]

Author:

{u'username': u'milkie', u'name': u'Eric Milkie', u'email': u'milkie@10gen.com'}

Message: SERVER-13053 fix curop query field for index builds outside of createIndexes command
(cherry picked from commit 6849110b99b4fc4e9fd162ac897e1a8e5180e72e)
Branch: v2.6
https://github.com/mongodb/mongo/commit/d44539de6758237c8b6eaa57a59988fa5b6ef9ac

Comment by Githook User [ 21/Mar/14 ]

Author:

{u'username': u'milkie', u'name': u'Eric Milkie', u'email': u'milkie@10gen.com'}

Message: SERVER-13053 fix curop query field for index builds outside of createIndexes command
Branch: master
https://github.com/mongodb/mongo/commit/6849110b99b4fc4e9fd162ac897e1a8e5180e72e

Comment by Githook User [ 21/Mar/14 ]

Author:

{u'username': u'milkie', u'name': u'Eric Milkie', u'email': u'milkie@10gen.com'}

Message: SERVER-13053 track index builds explicitly instead of using CurOp
(cherry picked from commit 70c062eb0646506df8979b49c052a54e6e4f9f8e)
Branch: v2.6
https://github.com/mongodb/mongo/commit/586200c20f5bed4b3cf7184ba2e013d46bb4059d

Comment by Githook User [ 21/Mar/14 ]

Author:

{u'username': u'milkie', u'name': u'Eric Milkie', u'email': u'milkie@10gen.com'}

Message: SERVER-13053 track index builds explicitly instead of using CurOp
Branch: master
https://github.com/mongodb/mongo/commit/70c062eb0646506df8979b49c052a54e6e4f9f8e

Comment by Eric Milkie [ 21/Mar/14 ]

Log output will now look like this:

2014-03-21T10:20:06.200-0400 [conn1] build index on: foo.foo72 properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "foo.foo72" }
2014-03-21T10:20:06.200-0400 [conn1] 	 added index to empty collection
2014-03-21T10:20:06.200-0400 [conn1] build index on: foo.foo72 properties: { v: 1, key: { a: 1.0 }, name: "a_1", ns: "foo.foo72" }
2014-03-21T10:20:06.200-0400 [conn1] 	 added index to empty collection
2014-03-21T10:20:06.200-0400 [conn1] build index on: foo.foo72 properties: { v: 1, key: { x: 1.0 }, name: "x_1", ns: "foo.foo72" }
2014-03-21T10:20:06.200-0400 [conn1] 	 added index to empty collection
2014-03-21T10:20:06.200-0400 [conn1] command foo.$cmd command: createIndexes { createIndexes: "foo72", indexes: [ { name: "a_1", key: { a: 1.0 } }, { name: "a_2", key: { a: 1.0 } }, { name: "x_1", key: { x: 1.0 } } ] } keyUpdates:0 numYields:0 locks(micros) r:37 w:907 reslen:144 0ms

Comment by Eric Milkie [ 11/Mar/14 ]

My code proposal will generate a log that looks like this:

2014-03-11T14:32:34.445-0400 [conn1] build index on: test.foo72 properties: { v: 1, key: { a: 1.0 }, name: "a_1", ns: "test.foo72" }
2014-03-11T14:32:34.445-0400 [conn1] 	 added index to empty collection
2014-03-11T14:32:34.445-0400 [conn1] insert test.system.indexes query: { v: 1, key: { a: 1.0 }, name: "a_1", ns: "test.foo72" } keyUpdates:0 numYields:0  0ms
2014-03-11T14:32:34.445-0400 [conn1] build index on: test.foo72 properties: { v: 1, key: { x: 1.0 }, name: "x_1", ns: "test.foo72" }
2014-03-11T14:32:34.445-0400 [conn1] 	 added index to empty collection
2014-03-11T14:32:34.445-0400 [conn1] insert test.system.indexes query: { v: 1, key: { x: 1.0 }, name: "x_1", ns: "test.foo72" } keyUpdates:0 numYields:0  0ms
2014-03-11T14:32:34.445-0400 [conn1] command test.$cmd command: createIndexes { createIndexes: "foo72", indexes: [ { name: "a_1", key: { a: 1.0 } }, { name: "a_2", key: { a: 1.0 } }, { name: "x_1", key: { x: 1.0 } } ] } keyUpdates:0 numYields:0 locks(micros) r:37 w:823 reslen:144 0ms

Where each index build is individually profiled, in addition to the entire command. This works similar to the way batched inserts are being profiled.

Comment by Eric Milkie [ 05/Mar/14 ]

In order to help fix SERVER-12926, I'm planning to explicitly put the command name in the op string description, as you suggest, and we'll solve both tickets.

Generated at Thu Feb 08 03:30:29 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.