tinylog-org / tinylog

tinylog is a lightweight logging framework for Java, Kotlin, Scala, and Android
https://tinylog.org
Apache License 2.0
697 stars 82 forks source link

Suggesting improve initialization performance #753

Open timlueg opened 3 months ago

timlueg commented 3 months ago

Description

I was happy to see that there are logging libraries in java that don't need multiple 100s of milliseconds just for initialization.

Here I made some suggestions to reduces the tinylogs init performance further by ~10ms

Agreements

codecov[bot] commented 3 months ago

Codecov Report

Attention: Patch coverage is 95.45455% with 1 line in your changes missing coverage. Please review.

Project coverage is 94.31%. Comparing base (7590ad1) to head (292e94c).

Files Patch % Lines
...in/java/org/tinylog/runtime/ModernJavaRuntime.java 95.23% 1 Missing :warning:
Additional details and impacted files ```diff @@ Coverage Diff @@ ## v2.8 #753 +/- ## ============================================ + Coverage 94.25% 94.31% +0.05% + Complexity 2838 2835 -3 ============================================ Files 149 149 Lines 5502 5505 +3 Branches 727 723 -4 ============================================ + Hits 5186 5192 +6 + Misses 176 175 -1 + Partials 140 138 -2 ```

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.

pmwmedia commented 3 months ago

Thanks for the draft! I'm curious to observe your changes. Just let me know when you are done, so I can review the changes.

To answer your questions:

Use direct call instead of reflection in getCurrentProcess (unsure why it uses reflection here)

Reflections where used for compatibility with Android as Android doesn't provide the class ProcessHandle, which was a cause for issues. However, I don't think that this workaround is still required.

Use System.currentTimeMillis() instead of JVM start time. Really unsure if this would be acceptable but this save about 5ms it think.

The JVM start time is nice if tinylog will be initialized much later. However, if you can provide a benchmark that shows significant performance improvements, we can change this.

timlueg commented 2 months ago

ManagementFactory.getRuntimeMXBean().getStartTime(); Takes 6-10 ms on my system (with openjdk-22.0.1) Where as System.currentTimeMillis() takes <0.002 ms.

(It was tricky to get this project build locally (at least in Intellij), I experienced issues with JDK certificates, probably because of the old jdk version requirement. Don't want to spam more commits to get build in ci working)

pmwmedia commented 2 months ago

You can fix the build by applying these changes to ModernJavaRuntime.java:


    @IgnoreJRERequirement
    private static final class ClassNameExtractorByDepth implements Function<Stream<StackFrame>, String> {
        private final int depth;

        private ClassNameExtractorByDepth(final int depth) {
            this.depth = depth;
        }

        @Override
        public String apply(final Stream<StackFrame> frames) {
            return frames.skip(depth)
                    .findFirst()
                    .map(new ClassNameMapper())
                    .orElse(null);
        }
    }

    @IgnoreJRERequirement
    private static final class ClassNameExtractorByLoggerClassName implements Function<Stream<StackFrame>, String> {
        private final String loggerClassName;

        private ClassNameExtractorByLoggerClassName(final String loggerClassName) {
            this.loggerClassName = loggerClassName;
        }

        @Override
        public String apply(final Stream<StackFrame> stream) {
            return stream.map(new ClassNameMapper()).dropWhile(new Predicate<String>() {
                @Override
                public boolean test(final String name) {
                    return !name.equals(loggerClassName);
                }
            }).skip(1).findFirst().orElse(null);
        }
    }

    /**
     * Mapper for getting the class name from a {@link StackFrame}.
     */
    @IgnoreJRERequirement
    private static final class ClassNameMapper implements Function<StackFrame, String> {

        /** */
        private ClassNameMapper() {
        }

        @Override
        public String apply(final StackFrame stackFrame) {
            return stackFrame.getClassName();
        }

    }