[SERVER-47483] Logs from util_test unittest get suppressed Created: 10/Apr/20  Updated: 29/Oct/23  Resolved: 14/Apr/20

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

Type: Bug Priority: Major - P3
Reporter: Spencer Brody (Inactive) Assignee: Billy Donahue
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Depends
Problem/Incident
is caused by SERVER-47418 setMinimumLoggedSeverity in unittest/... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: Service arch 2020-04-20
Participants:
Linked BF Score: 22

 Description   

It looks like after the LogWithSamplingTest suite runs, all future log output from the util_test binary gets suppressed.

 

To demonstrate, compare the log output from running the LogWithSamplingTest suite and 1 other suite in util_test in two different orders.

TimeParsing suite first, we see logs from both suites:

> build/debug/mongo/util/util_test --suite=TimeParsing --suite=LogWithSamplingTest
build/debug/mongo/util/util_test: /opt/mongodbtoolchain/v3/lib/libcurl.so.4: no version information available (required by build/debug/mongo/util/net/libhttp_client.so)
{"t":\{"$date":"2020-04-10T22:11:26.831Z"},"s":"I", "c":"TEST", "id":23063, "ctx":"main","msg":"Running","attr":\{"suite":"TimeParsing"}}
{"t":\{"$date":"2020-04-10T22:11:26.831Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"DateAsISO8601UTC","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.831Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"DateAsISO8601Local","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.832Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"DateAsISO8601LocalNoColon","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.832Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"InvalidDates","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.833Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"LeapYears","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.834Z"},"s":"I", "c":"TEST", "id":23060, "ctx":"main","msg":"Done running tests"}
{"t":\{"$date":"2020-04-10T22:11:26.834Z"},"s":"I", "c":"TEST", "id":23063, "ctx":"main","msg":"Running","attr":\{"suite":"LogWithSamplingTest"}}
{"t":\{"$date":"2020-04-10T22:11:26.834Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"ShouldLogCorrectlyWhenSampleRateIsSet","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:26.835Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"ShouldNotLogFastOp","rep":1,"reps":1}}

LogWithSamplingTest suite first, logs from TimeParsing suite disappear:

> build/debug/mongo/util/util_test --suite=LogWithSamplingTest --suite=TimeParsing
build/debug/mongo/util/util_test: /opt/mongodbtoolchain/v3/lib/libcurl.so.4: no version information available (required by build/debug/mongo/util/net/libhttp_client.so)
{"t":\{"$date":"2020-04-10T22:11:47.663Z"},"s":"I", "c":"TEST", "id":23063, "ctx":"main","msg":"Running","attr":\{"suite":"LogWithSamplingTest"}}
{"t":\{"$date":"2020-04-10T22:11:47.664Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"ShouldLogCorrectlyWhenSampleRateIsSet","rep":1,"reps":1}}
{"t":\{"$date":"2020-04-10T22:11:47.664Z"},"s":"I", "c":"TEST", "id":23059, "ctx":"main","msg":"Running","attr":\{"test":"ShouldNotLogFastOp","rep":1,"reps":1}}

This is getting in the way of our ability to debug certain build failures when tests within util_test fail.



 Comments   
Comment by Githook User [ 30/Apr/20 ]

Author:

{'name': 'Billy Donahue', 'email': 'billy.donahue@mongodb.com', 'username': 'BillyDonahue'}

Message: SERVER-47483 restore loggedSeverity after LogWithSamplingTest

(cherry picked from commit 5c72483523561c0331769abc3250cf623817883f)
Branch: v4.4
https://github.com/mongodb/mongo/commit/3734df0a10df705da3d21d8df7b037e60a48bd2d

Comment by Githook User [ 13/Apr/20 ]

Author:

{'name': 'Billy Donahue', 'email': 'billy.donahue@mongodb.com', 'username': 'BillyDonahue'}

Message: SERVER-47483 restore loggedSeverity after LogWithSamplingTest
Branch: master
https://github.com/mongodb/mongo/commit/5c72483523561c0331769abc3250cf623817883f

Comment by Billy Donahue [ 13/Apr/20 ]

CR https://mongodbcr.appspot.com/586530001/

Generated at Thu Feb 08 05:14:19 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.