Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Suppress logs in unit tests #8603

Closed
Akirathan opened this issue Dec 20, 2023 · 5 comments · Fixed by #8694
Closed

Suppress logs in unit tests #8603

Akirathan opened this issue Dec 20, 2023 · 5 comments · Fixed by #8694
Assignees
Labels
-compiler -tooling Category: tooling

Comments

@Akirathan
Copy link
Member

Akirathan commented Dec 20, 2023

The outputs of our unit tests are too verbose. Even if they succeed, we can see a lot of [ERROR] or [WARN] messages from various components that are just garbage. We should either suppress all the logs if the test succeeds, or print verbose logs if a test fails.

May be related to follow-ups of #7566

Might need tweaking our TestLogProvider

@JaroslavTulach
Copy link
Member

There is a prior work in NetBeans which works for JUnit3. Each NbTestCase has method logLevel (and also logRoot) and collects all logs of such severity into memory buffer. If the test succeeds the buffer is cleared. If it fails, it is appended to the error message.

@jdunkerley jdunkerley moved this from ❓New to 📤 Backlog in Issues Board Jan 2, 2024
@hubertp hubertp moved this from 📤 Backlog to 🔧 Implementation in Issues Board Jan 4, 2024
@hubertp hubertp moved this from 🔧 Implementation to 👁️ Code review in Issues Board Jan 5, 2024
@enso-bot
Copy link

enso-bot bot commented Jan 5, 2024

Hubert Plociniczak reports a new STANDUP for yesterday (2024-01-04):

Progress: Investigating if there is a way to suppress logs for successful tests. Reading documentation and discussions on scalatest it appears that nothing out-of-the-box exists and we have to invest something pretty custom. Also turned out that some ScalaTest test options were being completely ignored in sbt. Have a semi-working solution that seems to do the job. Investigating cloud issues with startup but nothing so far. It should be finished by 2024-01-05.

Next Day: Next day I will be working on the #8603 task. Cleanup the implementation and push the PR.

@enso-bot
Copy link

enso-bot bot commented Jan 8, 2024

Hubert Plociniczak reports a new STANDUP for the provided date (2024-01-05):

Progress: Prepared PR. Extra time was spent on making sure that tests behave as before if no trait mixin is present. Added a fix that removes the need for cats dependency import (#8696). It should be finished by 2024-01-05.

Next Day: Next day I will be working on the #8603 task. Address PR review

@mergify mergify bot closed this as completed in #8694 Jan 9, 2024
mergify bot pushed a commit that referenced this issue Jan 9, 2024
The change adds a convenient trait `ReportLogsOnFailure` that, when merged with the test class, will keep logs in memory and only delegate to the underlying appender on failure. For now we only support forwarding to the console which is sufficient.
A corresponding entry in `application-test.conf` has to point to the new `memory` appender. The additional complexity in the implementation ensures that if someone forgets to mixin `ReportLogsOnFailure` logs appear as before i.e. they respect the log level.

As a bonus fixed arguments passed to ScalaTest in build.sbt so that we are now, again, showing timings of individual tests.

Closes #8603.

# Important Notes
Before:
```
[info] VcsManagerTest:
[info] Initializing project
[ERROR] [2024-01-04 17:27:03,366] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must create a repository (3 seconds, 538 milliseconds)
[info] - must fail to create a repository for an already existing project (141 milliseconds)
[info] Save project
[ERROR] [2024-01-04 17:27:08,346] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must create a commit with a timestamp (198 milliseconds)
[ERROR] [2024-01-04 17:27:08,570] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must create a commit with a name (148 milliseconds)
[ERROR] [2024-01-04 17:27:08,741] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must force all pending saves (149 milliseconds)
[info] Status project
[ERROR] [2024-01-04 17:27:08,910] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must report changed files since last commit (148 milliseconds)
[info] Restore project
[ERROR] [2024-01-04 17:27:09,076] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must reset to the last state with committed changes (236 milliseconds)
[ERROR] [2024-01-04 17:27:09,328] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must reset to a named save (pending)
[ERROR] [2024-01-04 17:27:09,520] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] - must reset to a named save and notify about removed files *** FAILED *** (185 milliseconds)
[info]   Right({
[info]     "jsonrpc" : "2.0",
[info]     "method" : "file/event",
[info]     "params" : {
[info]       "path" : {
[info]         "rootId" : "cd84a4a3-fa50-4ead-8d80-04f6d0d124a3",
[info]         "segments" : [
[info]           "src",
[info]           "Bar.enso"
[info]         ]
[info]       },
[info]       "kind" : "Removed"
[info]     }
[info]   }) did not equal Right({
[info]     "jsonrpc" : "1.0",
[info]     "method" : "file/event",
[info]     "params" : {
[info]       "path" : {
[info]         "rootId" : "cd84a4a3-fa50-4ead-8d80-04f6d0d124a3",
[info]         "segments" : [
[info]           "src",
[info]           "Bar.enso"
[info]         ]
[info]       },
[info]       "kind" : "Removed"
[info]     }
[info]   }) (VcsManagerTest.scala:1343)
[info]   Analysis:
[info]   Right(value: Json$JObject(value: object[jsonrpc -> "2.0",method -> "file/event",params -> {
[info]   "path" : {
[info]     "rootId" : "cd84a4a3-fa50-4ead-8d80-04f6d0d124a3",
[info]     "segments" : [
[info]       "src",
[info]       "Bar.enso"
[info]     ]
[info]   },
[info]   "kind" : "Removed"
[info] }] -> object[jsonrpc -> "1.0",method -> "file/event",params -> {
[info]   "path" : {
[info]     "rootId" : "cd84a4a3-fa50-4ead-8d80-04f6d0d124a3",
[info]     "segments" : [
[info]       "src",
[info]       "Bar.enso"
[info]     ]
[info]   },
[info]   "kind" : "Removed"
[info] }]))
[ERROR] [2024-01-04 17:27:09,734] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/3607843843826594318].
[info] List project saves
[info] - must return all explicit commits (146 milliseconds)
[info] Run completed in 9 seconds, 270 milliseconds.
[info] Total number of tests run: 9
[info] Suites: completed 1, aborted 0
[info] Tests: succeeded 8, failed 1, canceled 0, ignored 0, pending 1
[info] *** 1 TEST FAILED ***
```

After:
```
[info] VcsManagerTest:
[info] Initializing project
[info] - must create a repository (3 seconds, 554 milliseconds)
[info] - must fail to create a repository for an already existing project (164 milliseconds)
[info] Save project
[info] - must create a commit with a timestamp (212 milliseconds)
[info] - must create a commit with a name (142 milliseconds)
[info] - must force all pending saves (185 milliseconds)
[info] Status project
[info] - must report changed files since last commit (142 milliseconds)
[info] Restore project
[info] - must reset to the last state with committed changes (202 milliseconds)
[info] - must reset to a named save (pending)
[ERROR] [2024-01-04 17:24:55,738] [org.enso.languageserver.search.SuggestionsHandler] Cannot read the package definition from [/tmp/8456553964637757156].
[info] - must reset to a named save and notify about removed files *** FAILED *** (186 milliseconds)
[info]   Right({
[info]     "jsonrpc" : "2.0",
[info]     "method" : "file/event",
[info]     "params" : {
[info]       "path" : {
[info]         "rootId" : "965ed5c8-1760-4284-91f2-1376406fde0d",
[info]         "segments" : [
[info]           "src",
[info]           "Bar.enso"
[info]         ]
[info]       },
[info]       "kind" : "Removed"
[info]     }
[info]   }) did not equal Right({
[info]     "jsonrpc" : "1.0",
[info]     "method" : "file/event",
[info]     "params" : {
[info]       "path" : {
[info]         "rootId" : "965ed5c8-1760-4284-91f2-1376406fde0d",
[info]         "segments" : [
[info]           "src",
[info]           "Bar.enso"
[info]         ]
[info]       },
[info]       "kind" : "Removed"
[info]     }
[info]   }) (VcsManagerTest.scala:1343)
[info]   Analysis:
[info]   Right(value: Json$JObject(value: object[jsonrpc -> "2.0",method -> "file/event",params -> {
[info]   "path" : {
[info]     "rootId" : "965ed5c8-1760-4284-91f2-1376406fde0d",
[info]     "segments" : [
[info]       "src",
[info]       "Bar.enso"
[info]     ]
[info]   },
[info]   "kind" : "Removed"
[info] }] -> object[jsonrpc -> "1.0",method -> "file/event",params -> {
[info]   "path" : {
[info]     "rootId" : "965ed5c8-1760-4284-91f2-1376406fde0d",
[info]     "segments" : [
[info]       "src",
[info]       "Bar.enso"
[info]     ]
[info]   },
[info]   "kind" : "Removed"
[info] }]))
[info] List project saves
[info] - must return all explicit commits (131 milliseconds)
[info] Run completed in 9 seconds, 400 milliseconds.
[info] Total number of tests run: 9
[info] Suites: completed 1, aborted 0
[info] Tests: succeeded 8, failed 1, canceled 0, ignored 0, pending 1
[info] *** 1 TEST FAILED ***
```
@github-project-automation github-project-automation bot moved this from 👁️ Code review to 🟢 Accepted in Issues Board Jan 9, 2024
@enso-bot
Copy link

enso-bot bot commented Jan 10, 2024

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2024-01-08):

Summary: There is 3 days delay in implementation of the Suppress logs in unit tests (#8603) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Distracted by failures in CI and investigating bugs reported in the meantime

@enso-bot
Copy link

enso-bot bot commented Jan 10, 2024

Hubert Plociniczak reports a new STANDUP for the provided date (2024-01-08):

Progress: Addressed PR review. Experimenting with optimizing compiler phases (AliasAnalysis), trying to run benchmarks to confirm the findings. Started looking into resurrecting Arrow PR. It should be finished by 2024-01-08.

Next Day: Next day I will be working on the #7755 task. Back to Arrow

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
-compiler -tooling Category: tooling
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants