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

Make the logging in std-benchmarks less verbose #12363

Merged
merged 4 commits into from
Feb 27, 2025

Conversation

Akirathan
Copy link
Member

@Akirathan Akirathan commented Feb 25, 2025

DEBUG and TRACE logs are flooding our CI, as well as local machines, during stdlib benchmark runs. See for example https://github.com/enso-org/enso/actions/runs/13510520512/job/37749655756#step:10:14949. This PR sets the default logback log level to INFO and it also ensures that std-benchmarks use the Enso logging infrastructure, rather than ch.qos.logback directly (see #12363 (comment))

@Akirathan Akirathan added the CI: No changelog needed Do not require a changelog entry for this PR. label Feb 25, 2025
@Akirathan Akirathan self-assigned this Feb 25, 2025
<!DOCTYPE configuration>

<configuration>
<import class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"/>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We are using application.conf at other places. Shouldn't we use the same format for configuring logging everywhere? CCing @hubertp

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have tried it, but it doesn't work in this case. I don't know why, probably because our logging initialization does not know where to find the configuration file?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You have explicitly set the provider to LogbackServiceProvider so yeah, it definitely is not using our service provider so it will not pick up the file.
I think it would be better to use application.conf like in the other places.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

After 4059c2a, std-benchmarks use the Enso logging infrastructure, and there is std-bits/benchmarks/src/main/resources/application-test.conf.

The output from running some benchmark from std-benchmarks now looks like this:

sbt:std-benchmarks> run -wi 2 -i 1 ^org.enso.benchmarks.generated.Vector_Operations.Partition$
[info] Assembly jar up to date: /home/pavel/dev/enso/lib/java/fansi-wrapper/target/scala-2.13/fansi-wrapper-assembly-0.1.0-SNAPSHOT.jar
[info] Assembly jar up to date: /home/pavel/dev/enso/lib/java/scala-libs-wrapper/target/scala-2.13/scala-libs-wrapper-assembly-0.1.0-SNAPSHOT.jar
[info] running (fork) org.enso.benchmarks.libs.LibBenchRunner -wi 2 -i 1 ^org.enso.benchmarks.generated.Vector_Operations.Partition$
[info] ::group::org.enso.benchmarks.generated.Vector_Operations.Partition
[info] # Run progress: 0.00% complete, ETA 00:00:15
[info] # Fork: 1 of 1
[info] OpenJDK 64-Bit Server VM warning: -XX:ThreadPriorityPolicy=1 may require system level permission, e.g., being the root user. If the necessary permission is not possessed, changes to priority will be silently ignored.
[info] # Warmup Iteration   1: LoggerSetup.get
[error] SLF4J(I): Attempting to load provider "org.enso.logging.service.logback.test.provider.TestLogProvider" specified via "slf4j.provider" system property
[info] [WARN] [2025-02-26 13:56:39,785] [enso.org.enso.interpreter.runtime.EnsoContext] Initializing the context in a different working directory than the one containing the project root. This may lead to relative paths not behaving as advertised by `File.new`. Please run the engine inside of `/home/pavel/dev/enso/test` directory.
[info] [INFO] [2025-02-26 13:56:40,231] [org.enso.interpreter.runtime.DefaultPackageRepository] Found library Standard.Base @ 0.0.0-dev at [/home/pavel/dev/enso/distribution/lib/Standard/Base/0.0.0-dev].
[info] [INFO] [2025-02-26 13:56:40,281] [org.enso.interpreter.runtime.DefaultPackageRepository] Found library Standard.Test @ 0.0.0-dev at [/home/pavel/dev/enso/distribution/lib/Standard/Test/0.0.0-dev].
[info] [INFO] [2025-02-26 13:56:41,431] [org.enso.interpreter.runtime.DefaultPackageRepository] Found library Standard.Table @ 0.0.0-dev at [/home/pavel/dev/enso/distribution/lib/Standard/Table/0.0.0-dev].
[info] [INFO] [2025-02-26 13:56:41,781] [org.enso.interpreter.runtime.DefaultPackageRepository] Found library Standard.Examples @ 0.0.0-dev at [/home/pavel/dev/enso/distribution/lib/Standard/Examples/0.0.0-dev].
[info] [INFO] [2025-02-26 13:56:41,787] [org.enso.interpreter.runtime.DefaultPackageRepository] Found library Standard.Image @ 0.0.0-dev at [/home/pavel/dev/enso/distribution/lib/Standard/Image/0.0.0-dev].
[info] 254.829 ms/op
[info] # Warmup Iteration   2: 117.806 ms/op
[info] Iteration   1: Before WARMUP#1. Cleaning 465 compilation messages
[info] Before WARMUP#2. Cleaning 2701 compilation messages
[info] Before MEASUREMENT#1. Cleaning 5882 compilation messages
[info] After MEASUREMENT#1. Dumping 4491 compilation messages:
[info] opt deopt  id=2463  Builder.unsafe_append                              
[info] opt deopt  id=2459  Builder.append<arg-1>                              
[info] opt deopt  id=6966  Any.if_not_error <split-6966>                      
[info] opt deopt  id=6964  Builder.append<arg-1> <split-6964>                 
[info] opt deopt  id=6963  Builder.append <split-6963>                        
[info] opt deopt  id=6933  case_branch                                        
[info] opt deopt  id=6934  Array_Like_Helpers.partition.vecs.case vecs        
[info] opt deopt  id=6956  Array_Like_Helpers.map.Array_Like_Helpers.map <split-6956> 
[info] opt deopt  id=2463  Builder.unsafe_append                              
[info] opt deopt  id=2459  Builder.append<arg-1>
...

out.println(" ctxFactory.projectRoot(projectRootDir.getAbsolutePath());");
out.println(" ctxFactory.options(options);");
out.println(" ctxFactory.logHandler(logHandler);");
out.println(" var ctx = ctxFactory.build();");
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ctxFactory.build() ensures that Enso logging infrastructure is initialized.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As well as ensuring the consistency in how we are building org.graalvm.polyglot.Context from CLI, Language server, and from benchmarks.

Copy link
Collaborator

@hubertp hubertp left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Much better with application.conf. Thanks!

@Akirathan Akirathan added the CI: Ready to merge This PR is eligible for automatic merge label Feb 26, 2025
@Akirathan Akirathan merged commit 0e54062 into develop Feb 27, 2025
70 of 71 checks passed
@Akirathan Akirathan deleted the wip/akirathan/quiet-stdbench-logger branch February 27, 2025 13:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
CI: No changelog needed Do not require a changelog entry for this PR. CI: Ready to merge This PR is eligible for automatic merge
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants