Performance tests

[whiskeysierra]

Since we are logging the message body most users will rightly question how fast this is and what performance penalty they should expect.

• [x] implement tests
• [ ] put results in the readme

[skjolber]

So would it make sense to first go with a JMH style benchmarking and then perhaps later move on to a full spring boot example app + load testing tool like Gatling?

The overall impact in a full spring boot app will probably be relatively low, perhaps 10%.

[whiskeysierra]

So would it make sense to first go with a JMH style benchmarking and then perhaps later move on to a full spring boot example app + load testing tool like Gatling?

Absolutely.

[tkrop]

I'm not absolutely sure about what a performance test would bring here. Primarily it would measure buffer to I/O copying. What should it be compared against, and what should a value tell the logbook user?

[whiskeysierra]

What should it be compared against

Against not using logbook. Users should have a clue how big the penalty is.

[tkrop]

Against not using logbook. Users should have a clue how big the penalty is.

Does not really make sense in my opinion, especially as logbook provides many customization switches and inefficiencies. Either users need to log or they do not need to log. The only aspects, that makes sense to test in my view, are to compare whether the selected solution has more overhead than another default or handwritten solution, or to find out whether the solution has an efficiency problem.

For the latter one I would use small micro-performance tests on the utilized components that will not have any meaning for the users. By the way, if we really care about performance and penalties, we should start by optimizing the formatters - in this classes I can just see the inefficiencies by reviewing the code.

[whiskeysierra]

compare whether the selected solution has more overhead than another default or handwritten solution

That's the biggest motivator for me. Comparing against https://github.com/zalando/logbook#alternatives, for example.

[skjolber]

Note on JsonHttpLogFormatter - it slows it down first calling prepare(..) then format(..) (in StructuredHttpLogFormatter), that should really be a single step for converting right to JSON.

[whiskeysierra]

You mean the intermediate map is too heavy?

[skjolber]

Well at least wasteful. A JsonWriter or (even faster) a StringBuilder is preferable.

[whiskeysierra]

Well. I believe we have bigger issues. Or at least I'd like to make sure that this is the biggest performance issue we have :stuck_out_tongue_winking_eye:

[skjolber]

These jackson objects are a bit heavy, so my guess is that this will be in the 10 percent range improvement. Filtering the payloads will be the most demanding part I think. I've written this filter for XML:

https://github.com/skjolber/xml-log-filter

But have yet to see a similar JSON log filter using the same approach.

So would a gradle-based approach with JMH and a visualizer be a good starting point? Like https://github.com/skjolber/java-jwt-benchmark ?

[whiskeysierra]

So would a gradle-based approach with JMH and a visualizer be a good starting point? Like https://github.com/skjolber/java-jwt-benchmark ?

I'd love that! :heart:

[skjolber]

@whiskeysierra okey, can you create a repository like logbook-benchmark, logbook-jmh etc? I'll drop in the project sceleton (copy from java-jwt-benchmark) with a few PoC tests. I cant promise to write very many tests, outside the JSON-related parts, but probably this will get the ball rolling.

[whiskeysierra]

Can we create those as modules within this repository?

[skjolber]

Should be possible, for project setup the most important is to get a jmh-visualizer (i.e. https://github.com/jzillmann/jmh-visualizer) automatically hooked into JMH output and being able to run just a subset of the benchmarks at a time.

It is possible to do with pure text, but a visualization is really better.

[skjolber]

I've not found a maven plugin for this jmh visualizer yet though.

[whiskeysierra]

Leave the visualizer to me. Maybe I will produce it by hand specifically for this project.

Doesn't look so hard https://github.com/jzillmann/gradle-jmh-report/blob/master/src/main/kotlin/io/morethan/jmhreport/gradle/task/JmhReportTask.kt

[skjolber]

Is this your first Maven plugin? :chart_with_downwards_trend: There is always drag'n drop to https://jmh.morethan.io.

[skjolber]

I'll have to split this into multiple PRs. First a new module logbook-jmh and a README with some instructions. I think release and unit test coverage should be dropped from the new module.

There might be issues with competing implementations down the road, but lets cross that bridge then.

You will in general have to accept PRs with baseline benchmarks before actually accepting PRs with performance-enhancing changing.

Results so far:

• Logbook is more fast than slow.
• Default HttpLogFormatter is slow, however performance can be improved a lot.
• JsonHttpLogFormatter is faster than expected.
• JsonMediaType runs a lot of times, its performance can be improved a lot.
• There is a JSON filter for filtering a JWT client credentials request by default.

This might be a good time to discuss benchmarking in this project:

• Inevitably, faster implementations will be more complex than the base implementations.
  • balance excellent performance against trashing the codebase.
  • Simpler implementations might still be kept around as part of unit testing.
    • Running operations multiple thousand times a second might seem overkill, but it does make sense to relate the time spent as
    • improved response time (we're going to run the code > 10 times in some cases)
    • alternative use of CPU time, both internally and externally
• checklist for submitting benchmarks

[skjolber]

Added https://github.com/zalando/logbook/pull/511. Have a few improvements after it lands. Lets just go with the online visualizer for now.

[skjolber]

The current merge(left, right) pattern makes collecting multiple operations into one, like remove or replace headers, impossible. So each operation needs to create new objects (like TreeMap) which slows performance down.

[skjolber]

FYI an 'ugly' rewrite of the Json HTTP Logger did improve performance, but no more than 10-25%.

https://github.com/zalando/logbook/compare/master...skjolber:jmhJsonHttpLogFormatter

I am guessing you think thats is not worth it.

[skjolber]

I suspect SplunkHttpLogFormatter would see a significant performance improvement by moving to using a StringBuilder, if anyone (@nsmolenskii) is interested in giving it a go.