[SERVER-16324] Command execution log line displays "query not recording (too large)" instead of abbreviated command object Created: 25/Nov/14  Updated: 11/Jul/16  Resolved: 25/Nov/14

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: 2.6.5, 2.8.0-rc1
Fix Version/s: 2.6.6, 2.8.0-rc2

Type: Bug Priority: Major - P3
Reporter: J Rassi Assignee: J Rassi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by SERVER-14990 Do not omit the information about the... Closed
is duplicated by SERVER-18173 Being able to control the length of '... Closed
Related
related to SERVER-1794 make CurOp query's lifespan same as t... Closed
related to SERVER-6218 Profile documents should include part... Closed
related to SERVER-13952 Cache partial BSONObj if possible (in... Closed
is related to SERVER-12049 Redact password data from profiler/sl... Closed
Operating System: ALL
Backport Completed:
Participants:

 Description   

When a command with a large command object is run and the operation is logged, the message "query not recording (too large)" is recorded in the log line instead of the abbreviated command object.

To reproduce, run the following snippet with the mongo shell:

var str = ''; for (i=0; i<512; ++i) { str += 'a'; }; db.foo.count({a: str});

When run against a 2.6.5 mongod with the verbose flag set, this command generates the following entry in the mongod log:

2014-11-25T16:23:52.809-0500 [conn1] command test.$cmd command: count { $msg: "query not recording (too large)" } keyUpdates:0 numYields:0 locks(micros) W:895 r:60 reslen:58 0ms

This is a regression introduced in 2.5.5 by <https://github.com/mongodb/mongo/commit/bc25799bbeaee8e6133804ffa6fece31e8a62236#diff-96c987e2693d90345a318d2681e2c45eR604>. The issue is that the command object is read out of CurOp::_query (which is limited in size) instead of OpDebug::query.

When run against 2.4.12, an abbreviated version of the query is logged instead, as expected:

Tue Nov 25 16:23:19.739 [conn1] command test.$cmd command: { count: "foo", query: { a: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa..." }, fields: {} } ntoreturn:1 keyUpdates:0 locks(micros) W:232 r:29 reslen:58 0ms



 Comments   
Comment by Githook User [ 25/Nov/14 ]

Author:

{u'username': u'jrassi', u'name': u'Jason Rassi', u'email': u'rassi@10gen.com'}

Message: SERVER-16324 OpDebug::report() should read query from OpDebug, not CurOp

(cherry picked from commit 8f0d423946be1873d0af5c6db488d2bee9629899)
Branch: v2.6
https://github.com/mongodb/mongo/commit/dfe24c01783660cd923ca2a07e61dbb16ac8c736

Comment by Githook User [ 25/Nov/14 ]

Author:

{u'username': u'jrassi', u'name': u'Jason Rassi', u'email': u'rassi@10gen.com'}

Message: SERVER-16324 OpDebug::report() should read query from OpDebug, not CurOp
Branch: master
https://github.com/mongodb/mongo/commit/8f0d423946be1873d0af5c6db488d2bee9629899

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