[SERVER-74368] Reduce log verbosity for virtual collection queries Created: 24/Feb/23  Updated: 29/Oct/23  Resolved: 03/Apr/23

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 7.0.0-rc0, 6.3.2

Type: Improvement Priority: Major - P3
Reporter: Divjot Arora (Inactive) Assignee: Serhii Lysenko
Resolution: Fixed Votes: 0
Labels: neweng
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
Related
related to SERVER-80367 Set all virtual collection query logs... Closed
Assigned Teams:
Query Execution
Backwards Compatibility: Fully Compatible
Backport Requested:
v6.3
Sprint: QE 2023-03-20, QE 2023-04-03, QE 2023-04-17
Participants:

 Description   

Queries against virtual collections (e.g. queries that specify named pipes for data transfer) currently result in these log messages:

{"t":{"$date":"2023-02-20T12:58:48.095-08:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"conn3","msg":"createCollection","attr":{"namespace":"test.named_pipe_1","uuidDisposition":"generated","uuid":{"uuid":{"$uuid":"31c6b2ac-3dfc-4965-9738-a484c2ebd43d"}},"options":{"autoIndexId":false}}}
{"t":{"$date":"2023-02-20T12:58:48.095-08:00"},"s":"I",  "c":"STORAGE",  "id":7005001, "ctx":"conn3","msg":"Named pipe is closed","attr":{"path":"/tmp/named_pipe_1"}}
{"t":{"$date":"2023-02-20T12:58:48.095-08:00"},"s":"I",  "c":"STORAGE",  "id":7005001, "ctx":"conn3","msg":"Named pipe is closed","attr":{"path":"/tmp/named_pipe_1"}}
{"t":{"$date":"2023-02-20T12:58:48.095-08:00"},"s":"I",  "c":"STORAGE",  "id":20318,   "ctx":"conn3","msg":"Finishing collection drop","attr":{"namespace":"test.named_pipe_1","uuid":{"uuid":{"$uuid":"31c6b2ac-3dfc-4965-9738-a484c2ebd43d"}}}}

This is a significant amount of logging for a single query, especially because create/dropping of the collection now goes from a log that is only published infrequently in OLTP workloads to being published for every query. To reduce the verbosity here, we should:

1. Change create/drop collection to be DEBUG level for virtual collections.
2. Deduplicate the "Named pipe is closed" message so it is only published once.



 Comments   
Comment by Githook User [ 18/Apr/23 ]

Author:

{'name': 'Serhii Lysenko', 'email': 'serhii.lysenko@mongodb.com', 'username': 'serhiitea'}

Message: SERVER-74368 Reduce log verbosity for virtual collection queries
Branch: v6.3
https://github.com/mongodb/mongo/commit/97902a8d154d5307e5f83d64917607526d8ec735

Comment by Githook User [ 21/Mar/23 ]

Author:

{'name': 'Serhii Lysenko', 'email': 'serhii.lysenko@mongodb.com', 'username': 'serhiitea'}

Message: SERVER-74368 Reduce log verbosity for virtual collection queries
Branch: master
https://github.com/mongodb/mongo/commit/a807e0808239ec92ed7c091dc4a6c02de064a98a

Comment by Serhii Lysenko [ 09/Mar/23 ]

divjot.arora@mongodb.com
Could you please provide an example of the query that reproduces this behaviour?

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