Reduce verbosity of CleanupSession debug logs. #5209
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Currently we wait up to 10s for this operation to complete. Replacing the two log lines with three, lets us halve the number of logs printed every 10ms, but always print exactly one log line each iteration of the loop. Rather than: ``` 02-10 19:58:48.880 3140 3140 D CleanupSession: Wait for all Realm instance to be closed (29 - 0) 02-10 19:58:48.880 3140 3140 D CleanupSession: Waiting 10ms 02-10 19:58:48.890 3140 3140 D CleanupSession: Wait for all Realm instance to be closed (29 - 0) 02-10 19:58:48.890 3140 3140 D CleanupSession: Waiting 10ms 02-10 19:58:48.900 3140 3140 D CleanupSession: Wait for all Realm instance to be closed (29 - 0) 02-10 19:58:48.900 3140 3140 D CleanupSession: Waiting 10ms 02-10 19:58:48.910 3140 3140 D CleanupSession: Wait for all Realm instance to be closed (29 - 0) 02-10 19:58:48.910 3140 3140 D CleanupSession: Waiting 10ms 02-10 19:58:48.920 3140 3140 D CleanupSession: Wait for all Realm instance to be closed (0 - 0) ``` We'll print: ``` 02-10 19:58:48.880 3140 3140 D CleanupSession: Waiting 10ms for all Realm instance to be closed (29 - 0) 02-10 19:58:48.890 3140 3140 D CleanupSession: Waiting 10ms for all Realm instance to be closed (29 - 0) 02-10 19:58:48.900 3140 3140 D CleanupSession: Waiting 10ms for all Realm instance to be closed (29 - 0) 02-10 19:58:48.910 3140 3140 D CleanupSession: Waiting 10ms for all Realm instance to be closed (29 - 0) 02-10 19:58:48.920 3140 3140 D CleanupSession: Finished waiting for all Realm instance to be closed (0 - 0) ``` The above example took 40ms to finish and saved 4 log lines; you can see how it adds up if you take 10000ms to finish.
|
(for example the logs here: https://github.com/vector-im/element-android/suites/5263938080/artifacts/162501857 are quite long) |
Matrix SDKIntegration Tests Results:
|
While a lot of these integration tests are failing, this is also true for current develop https://github.com/vector-im/element-android/runs/5157323975?check_suite_focus=true where 17 of them are failing. I think this is safe to merge. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Type of change
Content
Debug logging for CleanupSession has been combined into a single log line.
Motivation and context
When reading the logs from some of the integration tests, there were periods of up to 10s of these logs being generated, which was a lot to scroll through.
Currently we wait up to 10s for this operation to complete.
Replacing the two log lines with three, lets us halve the number of logs printed every 10ms,
but always print exactly one log line each iteration of the loop. Rather than:
We'll print:
The above example took 40ms to finish and saved 4 log lines; you can see how it adds up to a lot of logs if you take 10000ms to finish.
Screenshots / GIFs
N/A
Tests
Inspected logging before/after
Tested devices
Checklist