[SERVER-18971] Command log lines should include ok: 0 and errmsg:"..." Created: 15/Jun/15  Updated: 01/Feb/18  Resolved: 01/Feb/18

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: None
Fix Version/s: 3.7.2

Type: Improvement Priority: Major - P3
Reporter: Kevin Pulo Assignee: Kevin Pulo
Resolution: Done Votes: 4
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by SERVER-27669 Not all errors are logged Closed
Related
is related to SERVER-20940 Should log createIndexes failure at l... Closed
Backwards Compatibility: Minor Change
Sprint: Sharding 2017-12-04, Sharding 2018-01-01, Sharding 2017-12-18, Sharding 2018-01-29, Sharding 2018-02-12
Participants:

 Description   

Results from commands are often not available. This means that when commands are logged, if only the logfile is available it is impossible to know whether the command succeeded or failed.

Thus log lines for failed commands should indicate ok:0, and include any errmsg:"..." that was in the command response.

For example, the following situation:

> rs.stepDown()
replset:PRIMARY> rs.stepDown()
{
    "closest" : NumberLong(0),
    "difference" : NumberLong(1434366203),
    "ok" : 0,
    "errmsg" : "no secondaries within 10 seconds of my optime"
}

should be logged as:

-2015-06-15T21:39:43.507+1000 [conn8] command admin.$cmd command: replSetStepDown { replSetStepDown: 60.0 } keyUpdates:0 numYields:0  reslen:132 0ms
+2015-06-15T21:39:43.507+1000 [conn8] command admin.$cmd command: replSetStepDown { replSetStepDown: 60.0 } keyUpdates:0 numYields:0  ok:0 errMsg:"no secondaries within 10 seconds of my optime" errName:ExceededTimeLimit errCode:50 reslen:132 0ms



 Comments   
Comment by Githook User [ 01/Feb/18 ]

Author:

{'email': 'kevin.pulo@mongodb.com', 'name': 'Kevin Pulo', 'username': 'devkev'}

Message: SERVER-18971 fix OpDebug::errInfo rename in service_entry_point_embedded
Branch: master
https://github.com/mongodb/mongo/commit/ad7235f3b739c3aeb0c21ddaba58fd1cb494cc61

Comment by Githook User [ 01/Feb/18 ]

Author:

{'email': 'kevin.pulo@mongodb.com', 'name': 'Kevin Pulo', 'username': 'devkev'}

Message: SERVER-18971 log command success/failure
Branch: master
https://github.com/mongodb/mongo/commit/4ec29b020efe0909b561b671f4f4cd202a4d8bab

Comment by Kevin Pulo [ 03/Nov/17 ]

Is the intent to always log both "ok: 0" and "ok: 1"? I.e. log successes as well as failures?

The original intent was to log "ok:1" for successful ops, however the feeling now is more that this should be avoided (ie. only add "ok:0" to failed ops) so as to:

  • minimise potentially backward-breaking changes, and
  • minimise log volume in the common case.

Could logging errmsg leak any sensitive information?

The errmsg will be have redaction applied in the same way as exception messages currently do, which I expect should be sufficient.

Comment by David Golden [ 27/Oct/17 ]

Two questions:

  • Is the intent to always log both "ok: 0" and "ok: 1"? I.e. log successes as well as failures?
  • Could logging errmsg leak any sensitive information?
Generated at Thu Feb 08 03:49:25 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.