Only time type/method matching if the debug logging is enabled

[tobiasstadler]

What does this PR do?

Increase matching performance when debug logging is not enabled.

Checklist

• This is something else
  • I have updated CHANGELOG.asciidoc

[github-actions]

👋 @tobiasstadler Thanks a lot for your contribution!

It may take some time before we review a PR, so even if you don’t see activity for some time, it does not mean that we have forgotten about it.

Every once in a while we go through a process of prioritization, after which we are focussing on the tasks that were planned for the upcoming milestone. The prioritization status is typically reflected through the PR labels. It could be pending triage, a candidate for a future milestone, or have a target milestone set to it.

[ghost]

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

• Start Time: 2022-02-22T07:01:30.583+0000

• Duration: 54 min 55 sec

Test stats 🧪

Test	Results
Failed	0
Passed	2495
Skipped	16
Total	2511

💚 Flaky test report

Tests succeeded.

🤖 GitHub comments

To re-run your PR in the CI, just comment with:

• /test : Re-trigger the build.

• run benchmark tests : Run the benchmark tests.

• run jdk compatibility tests : Run the JDK Compatibility tests.

• run integration tests : Run the Agent Integration tests.

• run end-to-end tests : Run the APM-ITs.

• run windows tests : Build & tests on windows.

• run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

[eyalkoren]

Thanks for proposing this @tobiasstadler .

Do you have any measurement as to what this metric collection actually adds? I'd expect it to be extremely cheap, so mush so that it wouldn't worth this change, but if really saves something it makes sense.

In addition, log_level is dynamic, so theoretically this will disable the ability to start with higher logging level and still get this printed by changing it to debug before stopping the agent. Not a very common use case, I just wonder if this change adds value.

[tobiasstadler]

I did an unscientific experiment. I started my JBoss EAP together with some wars and looked at the time difference between the first and last line containing match for instrument (debug logging was enabled). If I use false instead of logger.isDebugEnabled() the difference was around 24s, wile with true instead of logger.isDebugEnabled() it was around 27s. So the JBoss started around 3s faster without meaning the instrumentation time.

[eyalkoren]

If that's a consistent thing, we may need to see why that is, but I highly doubt this difference comes only from the updates of these metrics. Did you try to repeat it a few times?

[tobiasstadler]

Yes, I did restart the server a couple of times. The non measuring start was always a little bit faster.

[tobiasstadler]

I will try a non JBoss application tomorrow.

[tobiasstadler]

I did a couple of runs with a non JBoss Application and non measuring the instrumentation was about 1s faster (around 9s compared to 10s).

[jackshirazi]

what is your clock source?

[eyalkoren]

Thanks for providing more insights @tobiasstadler 🙏
I didn't estimate the clock query overhead as so impactful.
In that case, we should definitely apply this optimization!
Let me know if you want to apply the style change that you proposed, I think it makes sense.

[eyalkoren]

/test

[tobiasstadler]

what is your clock source?

Standard Mac Book Pro from 2018 (no VM). Do you need to know anymore specific?

[eyalkoren]

/test

[eyalkoren]

run elasticsearch-ci/docs

[eyalkoren]

Thanks!

[tobiasstadler]

Thank You!