[SERVER-35035] Additional levels of command debugging Created: 17/May/18  Updated: 08/Jan/24

Status: Backlog
Project: Core Server
Component/s: Logging
Affects Version/s: None
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Ben McCann Assignee: Backlog - Security Team
Resolution: Unresolved Votes: 0
Labels: log-verbosity, logging, move-sec
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
is related to SERVER-18339 Log only warning, error or fatal mess... Closed
Assigned Teams:
Server Security
Participants:

 Description   

Even at level "1" of debugging, which is the lowest enabled debug level, the logs are pretty detailed:

2018-05-16T18:05:34.876-0700 I COMMAND [conn2] command test.user appName: "MongoDB Shell" command: find { find: "user", filter: { email: "test@aol.com" }, $db: "test" } planSummary: EOF keysExamined:0 docsExamined:0 cursorExhausted:1 numYields:0 nreturned:0 reslen:82 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount:{ r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 0ms

It would be helpful to add another level which is perhaps a bit less detailed so that we don't fill our logs so quickly trying to debug what commands are being sent to our server:

2018-05-16T18:05:34.876-0700 I COMMAND [conn2] command test.user command: find 



 Comments   
Comment by Farkas Levente [ 17/May/22 ]

it's totally unusable in production!

why is not possible to turn off all connection? 

the only thing is to turn off all connection attepmpt nothing else. is it possible?

Comment by Leoš Literák [ 20/Dec/21 ]

Every logging system allows to select a logging level from fatal error, errors, warning, info to debug and trace. Mongo has only debug (0) to trace (0). My unused node generates over 500 MB logs each day and I cannot stop it:

{{{"t":

{"$date":"2021-12-20T10:07:56.666+01:00"}

,"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn6237","msg":"client metadata","attr":{"remote":"10.0.0.3:57168","client":"conn6237","doc":{"driver":{"name":"nodej {"t":

{"$date":"2021-12-20T10:07:56.865+01:00"}

,"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn6235","msg":"Connection ended","attr":{"remote":"10.0.0.3:57044","connectionId":6235,"connectionCount":9}} {"t":

{"$date":"2021-12-20T10:07:56.866+01:00"}

,"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn6234","msg":"Connection ended","attr":{"remote":"10.0.0.3:57042","connectionId":6234,"connectionCount":8}} {"t":

{"$date":"2021-12-20T10:07:56.867+01:00"}

,"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn6236","msg":"Connection ended","attr":{"remote":"10.0.0.3:57046","connectionId":6236,"connectionCount":7}} {"t":

{"$date":"2021-12-20T10:07:56.868+01:00"}

,"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.0.0.3:57254","connectionId":6238,"connectionCount":8}} {"t":

{"$date":"2021-12-20T10:07:56.868+01:00"}

,"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"10.0.0.3:57256","connectionId":6239,"connectionCount":9}} }}

{{ "network" : {
"verbosity" : 0,
"asio" :

{ "verbosity" : -1 }

,
"bridge" :

{ "verbosity" : -1 }

,
"connectionPool" :

{ "verbosity" : -1 }

},}}

Recommandation of quite mode is silly because Mongo official documentation does not recommend it for production deployments.

 

Comment by Ramon Fernandez Marina [ 21/May/18 ]

chengas123, I'm sending this request to one of our Product managers for evaluation.

Comment by Ben McCann [ 18/May/18 ]

Yes, I'd like to log different messages, not fewer. Sorry if that wasn't clear

E.g. on log level 1 we could have:

  • the timestamp
  • the connection name
  • the user
  • the namespace
  • the command name

And on log level 2 we could have:

  • the timestamp when the command finished
  • the connection name
  • the user
  • the namespace
  • the command name
  • the app name
  • the query parameters
  • the planSummary
  • num docsExamined
  • cursorExhausted
  • numYields
  • nreturned
  • reslen
  • locks
  • protocol

One big reason I'm asking for this is that my internal corporate security team / SREs won't let me turn on debug logging because it logs PII by logging the command arguments / query parameters. If there were a lesser level of debug logging that I could use to track what's happening without them worrying about me collecting PII then that would be really helpful

Comment by Eric Milkie [ 18/May/18 ]

I see in your original description, you want a log line that shows the following four items of information:

  • the timestamp when the command finished
  • the connection name
  • the namespace
  • the command name

But no other information. If that is what you specifically want, we can consider that.

Comment by Eric Milkie [ 18/May/18 ]

I don't understand why you can set the debug log level but not the debug log component. Certainly if you chose log level "1" and component "COMMAND" you would receive less detail (fewer log messages) than what you currently receive by choosing level "1" but not choosing a component.
I'm not sure how that is different from what you are asking for; can you give an example? Do you want different log messages, instead of fewer?

Comment by Ben McCann [ 18/May/18 ]

I doubt our SRE team would let us turn off SSL unfortunately, but it is a creative option that I appreciate considering!

I don't think there's anything I can do on my side regarding configuring log levels or components because what I meant was that it seems like whether I set level "1" or "5" even at level "1" the logging is quite detailed already. It would be nice if what's being logged at level "1" currently was moved to "2" and there was some higher-level information logged for "1"

Comment by Eric Milkie [ 17/May/18 ]

There is also a server parameter that can help you fine-tune logging verbosity:
https://docs.mongodb.com/manual/reference/parameters/#param.logComponentVerbosity

I'm not sure what your exact use case is, but if you just want to see log lines with the COMMAND component at level "1" and no other components, you can use that server parameter to achieve that.

Comment by Andy Schwerin [ 17/May/18 ]

You can also set the log level for specific components, which might help here.

Comment by Daniel Pasette (Inactive) [ 17/May/18 ]

Hi Ben. It can be difficult to choose the right level at which to log for the debug logs. If you're trying to monitor the cmds being sent to the server, you might be able to leverage the report functionality in mongoreplay. It won't work if you've enabled SSL, but otherwise may be a good option.

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