[SERVER-36441] Don't truncate 'comment' command parameter in the slow query logs Created: 03/Aug/18  Updated: 17/Aug/23

Status: Backlog
Project: Core Server
Component/s: Diagnostics, Querying
Affects Version/s: None
Fix Version/s: None

Type: New Feature Priority: Minor - P4
Reporter: Harshad Dhavale Assignee: Backlog - Query Execution
Resolution: Unresolved Votes: 3
Labels: query-product-scope-1, query-product-urgency-3, query-product-value-3
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by SERVER-38809 Ensure "comment" field is always pres... Closed
Related
is related to SERVER-29794 Adding a comment to all commands Closed
is related to SERVER-27439 Large queries can omit comment in cur... Closed
is related to SERVER-28128 Add support for a "comment" parameter... Closed
Assigned Teams:
Query Execution
Participants:
Case:

 Description   

ISSUE DESCRIPTION

 

Currently, the following behavior is observed for the $comment field displayed in the mongodb logs.

  • The $comment field's length gets truncated to 150 characters, when it is captured in the logs.
  • Increasing the value for maxLogSizeKB, makes no difference. The $comment field length still gets truncated in the logs at 150 characters.

REPRODUCER

 

1. The following command can be run in the mongo shell - note the `AB` at the end of the $comment string:

 

replset:PRIMARY> db.<collectionName>.aggregate([ { $match: { $comment: "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXAB"} } ])

 

2. In the logs it will be observed that the $comment field gets truncated (note the `...` and no `AB` at the end):

command test.<collectionName> appName: "MongoDB Shell" command: aggregate { aggregate: "<collectionName>", pipeline: [ { $match: { $comment: "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX..." } } ]

3. Performing a character count on the length of the $comment field (the "XXXX...") will show they are `150 `characters.

 


FEATURE REQUEST

Requesting for a feature that allows for changing the length of the $comment field displayed in the logs.

 



 Comments   
Comment by Xiaochen Wu [ 17/Aug/23 ]

Product triage: the value and urgency are low. Sending it to backlog. 

Comment by Ana Meza [ 14/Aug/23 ]

Passing to Product to decide on priority

Comment by Andrew Morrow (Inactive) [ 02/Apr/19 ]

I would definitely agree that introducing knowledge of comment and $comment into the BSON library is a layer violation. I do worry about adding yet another parameter to BSONObj::toString and BSONElement::toString (the latter being where the limit is actually enforced). There are already too many options. Another concern is whether the alwaysFull set would eventually come to include dotted paths, which would be another layer violation, I think. This discussion has me once again wishing that we had a generic BSON visitation framework. That would allow customization of behavior at the point of use, rather than plumbing additional context into the heavily overworked ::toString methods. However, the visitor would need to be implemented without stack based recursion, making it somewhat tricky to implement.

Comment by David Bartley [ 29/Mar/19 ]

I'd be fine adding a "const set<string>& alwaysFull" argument to toString, or even just a string argument topLevelAlwaysFull if we only want to support "comment" (depending on how https://jira.mongodb.org/browse/SERVER-29794 turns out).

Comment by David Storch [ 28/Mar/19 ]

Hi bartle,

Thanks for looking into this! I'd be a bit worried about writing code deep in the BSONObj library that has logic specific to "comment" or "$comment". The BSONObj code itself should be agnostic as to what its contents are in order to present a generic interface to all callers. I think a preferable approach would be to add a new parameter to BSONObj::toString() so that the caller can describe which fields should not be truncated. My team doesn't actually own this code, so I'm not sure if acm has different thoughts on how we should achieve this. Once we agree on the broad strokes of the fix, a pull request would be awesome!

Best,
Dave

Comment by David Bartley [ 22/Mar/19 ]

The following simple patch fixes this (verified against 3.4):

diff --git a/src/mongo/bson/bsonobj.cpp b/src/mongo/bson/bsonobj.cpp
index bc0045f568..2a048c26f9 100644
--- a/src/mongo/bson/bsonobj.cpp
+++ b/src/mongo/bson/bsonobj.cpp
@@ -612,7 +612,10 @@ void BSONObj::toString(
             first = false;
         else
             s << ", ";
-        e.toString(s, !isArray, full, redactValues, depth);
+        if (!full && !isArray && (str::equals(e.fieldName(), "comment") || str::equals(e.fieldName(), "$comment")))
+            e.toString(s, !isArray, true, redactValues, depth);
+        else
+            e.toString(s, !isArray, full, redactValues, depth);
     }
     s << (isArray ? " ]" : " }");
 } 

If this seems like a reasonable approach, I can add some tests and send out a PR.

Comment by David Bartley [ 22/Mar/19 ]

I think this is a bit more difficult to change now, since logs are now run through output redaction first.  In OpDebug::report we may just want to iterate over query and/or cmdToLog.getObject(), looking for top-level comment fields, and for those, ultimately call toString with full=true?

Comment by Asya Kamsky [ 07/Jan/19 ]

This ticket tracks two related issues:

  • when log line exceeds the maximum the entire comment can be lost/missing
  • when log line does not exceed maximum the comment still gets truncated
Comment by Harshad Dhavale [ 06/Sep/18 ]

Hi david.storch,

Thanks for the detailed explanation of why the comment field gets truncated at 150 characters and the related details. That makes sense. A fix for the comment parameter (instead of $comment) would definitely help as well, cause it will help achieve the end-goal of recording the full comment-string in the logs.

Thanks again.

Regards,
Harshad

Comment by David Storch [ 06/Sep/18 ]

Hi harshad.dhavale,

Thanks for the improvement request. We made a similar improvement to the output of $currentOp under SERVER-27439, but these changes did not apply to the slow query log. Note that we also improved the aggregate command to accept a top-level comment parameter (SERVER-28128).

When we log CurOp::_opDescription, we end up invoking BSONObj's operator<< overload for StringBuilder. The default behavior of this overload is to truncate long strings to 150 bytes. This is true anywhere that we dump a BSONObj to a string (without explicitly specifying to print the entire object). This is important to ensure that long strings from user input do not cause other relevant information to be truncated from log lines or other debug output. Therefore, we would not make a general change to the stringification of BSONObj, but rather would fix this by writing special code to avoid the truncation of the comment field.

The most likely fix would apply to the comment find and aggregate command parameter, but not to the $comment match expression operator. For this reason, I would strongly encourage users who rely on $comment to switch over to the comment command parameter. Currently, only find and aggregate support the comment parameter, but SERVER-29794 would add support for all commands.

Generated at Thu Feb 08 04:43:06 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.