[SERVER-20206] cleanupOrphaned should log when it starts Created: 31/Aug/15 Updated: 19/Jul/16 Resolved: 08/Jul/16 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Sharding |
| Affects Version/s: | None |
| Fix Version/s: | 3.3.10 |
| Type: | Improvement | Priority: | Minor - P4 |
| Reporter: | Kevin Pulo | Assignee: | Sam Dunietz |
| Resolution: | Done | Votes: | 0 |
| Labels: | neweng, orphaned | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||
| Sprint: | Sharding 10 (02/19/16), Sharding 17 (07/15/16) | ||||||||
| Participants: | |||||||||
| Description |
|
Currently when running cleanupOrphaned, the log output looks like this:
The problem is that none of the initial messages mention "cleanupOrphaned". This means that while the command is in progress (eg. trying to diagnose a slow running cleanupOrphaned command), the only indication in the log is the initial "Deleter starting delete for" message. (Yes, it will be in currentOp, but this ticket is about the logfile). Unfortunately this message is also output by the RangeDeleter in other contexts (ie. chunk migrations), so its presence does not necessarily indicate that the cleanupOrphaned command was used. In addition, inexperienced users/operators/engineers might not be aware that they need to search the logs for "Deleter", which is less obvious than "cleanupOrphaned". It would be much better if cleanupOrphaned could log a message when it starts to make it clear that it's about to run a RangeDeleter. This could also be considered a special case of |
| Comments |
| Comment by Kevin Pulo [ 11/Jul/16 ] | |||||
|
Thanks! | |||||
| Comment by Githook User [ 08/Jul/16 ] | |||||
|
Author: {u'name': u'Sam Dunietz', u'email': u'sam.dunietz@10gen.com'}Message: | |||||
| Comment by Esha Maharishi (Inactive) [ 08/Jun/16 ] | |||||
|
Okay, sounds good. | |||||
| Comment by Kevin Pulo [ 08/Jun/16 ] | |||||
|
I would only add to adjust the phrasing of the log line on L105 to match, since it also currently starts with "orphaned data cleanup requested for". | |||||
| Comment by Esha Maharishi (Inactive) [ 07/Jun/16 ] | |||||
|
kevin.pulo, thanks so much! In summary, I'd suggest changing the log line on L116 to logLevel=0 and rephrasing the initial part from "orphaned data cleanup requested for" to "cleanupOrphaned requested for". If this doesn't get picked up by our interns, I'll do it at the end of our current sprint. | |||||
| Comment by Kevin Pulo [ 06/Jun/16 ] | |||||
|
esha.maharishi, thanks for looking into this!
You mean if it scans for deletes — but also if it knows that it doesn't need to (L105-106).
Absolutely.
I don't see any need to log at level 0 if the command returns quickly (either success or failure). So, the early returns above L116 (ie. L108, L97, L87) don't need any additional logging. And the returns after L116 (on L133/136), which might happen much later, will be adequately covered by the L116 logging once it's converted to be logLevel 0.
Absolutely. | |||||
| Comment by Esha Maharishi (Inactive) [ 02/Jun/16 ] | |||||
|
kevin.pulo, it seems like cleanupOrphaned logs a line at logLevel=1 if it actually performs any deletes: Would it be helpful if:
—
|