Assertj-core: 3.9.1 has bad performance regression

[testn]

Summary

After upgrading to 3.9.1, I notice a regression in term of performance. By digging down, I notice that it spends a lot of time in the following code

  public static TypeComparators defaultTypeComparators() {
    TypeComparators comparatorByType = new TypeComparators();
    comparatorByType.put(Double.class, new DoubleComparator(DOUBLE_COMPARATOR_PRECISION));
    comparatorByType.put(Float.class, new FloatComparator(FLOAT_COMPARATOR_PRECISION));
    return comparatorByType;
  }

It sounds like it performs too much memory allocation and reflection cost on the following stack trace.

java.lang.Class.getEnclosingMethod0() Class.java (native)
java.lang.Class.getEnclosingMethodInfo() Class.java:1072
java.lang.Class.getEnclosingClass() Class.java:1272
java.lang.Class.getSimpleBinaryName() Class.java:1443
java.lang.Class.getSimpleName() Class.java:1309
org.assertj.core.internal.TypeComparators$$Lambda$77.apply(Object)
java.util.Comparator.lambda$comparing$77a9974f$1(Function, Object, Object) Comparator.java:469
java.util.Comparator$$Lambda$78.compare(Object, Object)
java.util.TreeMap.compare(Object, Object) TreeMap.java:1295
java.util.TreeMap.put(Object, Object) TreeMap.java:538
org.assertj.core.internal.TypeComparators.put(Class, Comparator) TypeComparators.java:99
org.assertj.core.internal.TypeComparators.defaultTypeComparators() TypeComparators.java:48
org.assertj.core.api.AbstractIterableAssert.<init>(Iterable, Class) AbstractIterableAssert.java:112
org.assertj.core.api.FactoryBasedNavigableIterableAssert.<init>(Iterable, Class, AssertFactory) FactoryBasedNavigableIterableAssert.java:32
org.assertj.core.api.IterableAssert.<init>(Iterable) IterableAssert.java:49
org.assertj.core.api.Assertions.assertThat(Iterable) Assertions.java:2586

This additional overhead is caused by the change from HashMap to TreeMap and the use of Comparator.comparing(Class::getSimpleName)

assertj 3.8.0 does not have this problem.

[PascalSchumacher]

Thanks for reporting!

The Comparator.comparing(Class::getSimpleName) change was part of https://github.com/joel-costigliola/assertj-core/commit/4402d598aeb45da32522201f1bc19b72747224a3 and can easily be undone.

The change from HashMap to TreeMap was to make the comparison more stable by always using comparators in insertion order.

AssertJ 3.9.0 contains only the Map type change. Any chance you can test how much the performance regession is with just this change?

[testn]

I use a lot of Assertions.assertThat in a tight loop. It pretty much consumes almost 100% of the cpu within the loop. I would suggest that you don't even get TypeComparators.defaultTypeComparators() at all. You should have a constant copy of that map and use it if the assert does not override that.

[robertotru]

We had the same issue. Upgraded from 3.8.0 to 3.9.1 and the runtime increased from 23 seconds to 4 minutes. We downgraded to 3.9.0, and the runtime was roughly the same as 3.8.0. Is there something I can do to provide more input?

[joel-costigliola]

@robertotru if you can provide a test showing the performance loss that would be great, we can always write it but having one from a real usage is better.

[PascalSchumacher]

Yes a test would be great. I tried my luck at a JHM test myself, but this simple test case:

public static class Bean {
    private double d = 1.00D;
    private int i = 1;
    private String s = "2";
    private float f = 1.0F;
    private Date date = new Date();
}

public static final Comparator<Integer> intComp = (i1, i2) -> {return 0; };
public static final Comparator<String> stringComp = (i1, i2) -> {return 0; };
public static final Comparator<Date> dateComp = (i1, i2) -> {return 0; };

@Benchmark
public void testMethod() {
    Bean bean = new Bean();
    assertThat(bean)
        .usingComparatorForType(intComp, Integer.class)
        .usingComparatorForType(stringComp, String.class)
        .usingComparatorForType(dateComp, Date.class)
        .isEqualToComparingFieldByField(bean);
}

only showed a performance regression of around 10 percent between 3.9.0 and 3.9.1.

[robertotru]

I understand. We have 2k unit tests, all using JUnitSoftAssertions rule. I'm not sure I can isolate/reproduce the issue in a single test file, let see what I can do.

[luengnat]

@PascalSchumacher TreeMap won't help much. If you want the type comparator by insertion order, it's better to use LinkedHashMap. BTW, the existing logic for get() does not rely on any order anyway.

  public Comparator<?> get(Class<?> clazz) {
    Comparator<?> comparator = typeComparators.get(clazz);

    if (comparator == null) {
      for (Class<?> superClass : ClassUtils.getAllSuperclasses(clazz)) {
        if (typeComparators.containsKey(superClass)) {
          comparator = typeComparators.get(superClass);
          break;
        }
      }

      if (comparator == null) {
        for (Class<?> interfaceClass : ClassUtils.getAllInterfaces(clazz)) {
          if (typeComparators.containsKey(interfaceClass)) {
            comparator = typeComparators.get(interfaceClass);
            break;
          }
        }
      }
    }
    return comparator;
  }

[PascalSchumacher]

@luengnat You are right. My statement concering insertion order was just a guess (and proably a wrong one).

@joel-costigliola made the change to TreeMap in https://github.com/joel-costigliola/assertj-core/commit/65c3487a0aa8ff83f25d4c84084c4e67a03f1922 I would now guess in order to have a defined element order when outputting used comparators in exception messages.

[joel-costigliola]

@PascalSchumacher yes I used a TreeMap for displaying the used comparators, I don't mind using another data structure as long as we have a consistent order.

[testn]

Let me take a stab at it

[PascalSchumacher]

Sure. 👍 Contributions are always welcome! 😃

[joel-costigliola]

Hi guys, anything new on this one?

[testn]

@joel-costigliola do you want a short simple change first? I wanted to do a major surgery but I'm afraid that it will break it.

The minimal change is to do something like this

  private static final Comparator<Class<?>> CLASS_COMPARATOR = Comparator.comparing(Class::getName);
  private static final DoubleComparator DEFAULT_DOUBLE_COMPARATOR = new DoubleComparator(DOUBLE_COMPARATOR_PRECISION);
  private static final FloatComparator DEFAULT_FLOAT_COMPARATOR = new FloatComparator(FLOAT_COMPARATOR_PRECISION);

  @VisibleForTesting
  Map<Class<?>, Comparator<?>> typeComparators;

  public static TypeComparators defaultTypeComparators() {
    TypeComparators comparatorByType = new TypeComparators();
    comparatorByType.put(Double.class, DEFAULT_DOUBLE_COMPARATOR);
    comparatorByType.put(Float.class, DEFAULT_FLOAT_COMPARATOR);
    return comparatorByType;
  }

private static final Comparator<Class<?>> CLASS_COMPARATOR = Comparator.comparing(Class::getName); will use getName() to sort rather than getSimpleName().

getName() is the name use to dynamically load the class with, for example, a call to Class.forName with the default ClassLoader i.e. java.util.AbstractMap$SimpleEntry
getCanonicalName() is the name used to uniquely identifies the class in the code i.e. java.util.AbstractMap.SimpleEntry
the simple name loosely identifies the class without the package name i.e. SimpleEntry

The above yields the biggest win as it can use the cached class name for comparison.

The second change is to create singletons of DEFAULT_DOUBLE_COMPARATOR and DEFAULT_FLOAT_COMPARATOR since they are thread-safe and safe for reusing.

[joel-costigliola]

I'm happy with these changes (the full class name is less nice to read when in the error messages but I can live with it), what I really would like to have is a test showing the performance improvements, I would run it with 3.9.0, then 3.9.1 to see the degradation and with the fix to see how things are compared to 3.9.0 and 3.9.1.

[testn]

@joel-costigliola from my testing with ObjectAssertions over with million iterations, with 3.9.1 code, it takes around 2 minutes. With the simple change, it seems to get down to 11 seconds.

Note that the change is to change the sorting order to include the package name, it does not change any error message at all.

[joel-costigliola]

@testn Do you want to create a PR ? I can also integrate your suggested changes directly if you don't have the time.

[testn]

Feel free to do so. If I get a chance, I might try to integrate the code change to do the lazy initialization for TypeComparators instead.

[joel-costigliola]

I'll do it then

[joel-costigliola]

@testn I have pushed the code (see https://github.com/joel-costigliola/assertj-core/commit/7c96b8d736a0afdd0e022546082d39accaa96b32), the main improvement comes from using Comparator.comparing(Class::getName), the performance test ran from ~700ms to ~240ms, it's not quite fixing the performance issue reported.
@robertotru can you give a try to assertj-core 3.10.0-SNAPSHOT and check how things are going ? (just run maven install to build assertj-core).

[DavidRigglemanININ]

I've seen similar performance regressions with 3.9.1 and have been watching this issue and thus ran my tests with 3.10.0-SNAPSHOT. For my set of tests (around 1400), 3.90 runs in around 50 seconds, 3.91 runs in around 70 seconds, and 3.10.0-SNAPSHOT runs in 65 seconds. So there was some improvement with the latest commit, but only addresses around 25% of the performance regression for my specific set of tests.

[joel-costigliola]

@DavidRigglemanININ thanks for the feedback, we will try to ship further improvements.

[joel-costigliola]

I have made further enhancements in https://github.com/joel-costigliola/assertj-core/commit/c415bc1f5c0ff5701e9dd1830d24a8f386c04e75, in my perf test the average execution went from 240ms to 160ms (from 700ms initially), a 4x factor.

The next improvement could be to make TypeComparators immutable so that the default comparator could be built once for all and another TypeComparators would be created instead of modifying the current one.

[DavidRigglemanININ]

The recent changes knocked off another 3 seconds for me (so 62 seconds for my set of tests, still up from the original 50)

[joel-costigliola]

I wonder guys if you are using soft assertions or not, we have replaced cglib by byte buddy, this might had an effect on performance (I will measure that soonish).

[DavidRigglemanININ]

I'm definitely using soft assertions and probably relatively heavily.

[joel-costigliola]

Just for the sake of testing, without doing anything in defaultTypeComparators() the perf test average execution time is ~80ms.

[joel-costigliola]

TypeComparators are now lazy initialized (see https://github.com/joel-costigliola/assertj-core/commit/bdf7291c85bfece24206fb9803002df5cd7e9b02) the perf test average execution time is ~80ms.

[testn]

@joel-costigliola looks great! But after looking at the code more carefully, it looks like you only use "TreeMap" for TypeComparators for toString() method which I don't even find where you use it. Don't you think it is more efficient to keep using HashMap and sort it lazily instead?

[joel-costigliola]

@testn I have switched from a TreeMap to a LinkedHashMap without seeing any significant performance improvements in the perf test I have written (but this test is not as realistic as a real project using assertj).

[testn]

@joel-costigliola, since you switch to use getName() instead of getSimpleName(), I would not expect a huge performance difference unless there are a lot of type comparators added into TypeComparators

[joel-costigliola]

I have run some performance tests on soft assertions, it turns out that moving to byte-buddy had a significant impact, they are ~2.5x slower.
We have moved to byte-buddy to fix some issues unsolvable with cglib (the previous proxying lib), we will have a look if we can improve our current usage of byte buddy.

[joel-costigliola]

@PascalSchumacher @robertotru can you run your tests with the latest 3.10.0-SNAPSHOT to measure the improvements done so far?

[filiphr]

I think byte buddy should be faster than cglib (at least from what I've read, I can't find that article now).

Probably something is not OK on our side. Maybe @raphw can help us out with the performance.

[raphw]

Performance is a difficult topic with code generation. On average, Byte Buddy performs better then cglib. But cglib is a much simpler library that does for example not process generics. Byte Buddy does so and creates method graphs to correctly generate bridge methods and to resolve generic parameter and return types. It also processes meta data such as annotations. All of these are costly operations on the JVM that cglib avoids. However, this processing is necessary if you want to avoid many quirks that ignoring this data entails which manifest as corner-case bugs in cglib. To test this, you can run your JVM with -Dnet.bytebuddy.raw=true where Byte Buddy discards most generic type information. You will most likely yield different code and run into bugs but it is a good start to get a performance baseline.

Another trade off is the speed of code generation compared to the speed of the generated code during execution. Byte Buddy favors the latter but for assertj, this trade of might not be ideal as it has no code-generating startup phase with indefinite runtime afterwards such as, for example, the average Hibernate application. If you create a lot of proxies with many methods and use them only a few times, the current setup might not be ideal as Byte Buddy creates a dedicated proxy for each @SuperCall to avoid unnecessary boxing. For the runtime of invoking a delegation, this helps a lot but it costs additional time during generation.

You are however mainly calling a super method as the first thing and then you go on. You can optimize this by not using MethodDelegation but rather Advice. With advice, you can implement your code as a static method annotated with @Advice.OnMethodExit and read the return value or a thrown value from there using @Advice.Return or @Advice.Thrown. Simply create an instance of Advice.to(yourAdviceClass).wrap(SuperMethodCall.INSTANCE) and cache (!) this rather expensive instance as a field value somewhere. This might just do the trick.

[joel-costigliola]

@raphw thanks for the feedback, we will try your suggestion on using Advice.

[raphw]

Great, let me know if you need help. Note that advice needs to be stateless. You can however define any amount of (static) fields using the type builder DSL and set values using reflection. You can the access these fields using Advice.FieldValue.

[testn]

the upgrade to bytebuddy 1.8.0 should already helped improve some performance already though.

[raphw]

I got some really good performance feedback by @testn and noticed that assertj recreates ByteBuddy instances for every class. They should also be configured by .with(TypeValidation.DISABLED) to avoid internal validation which is rather costly.

[joel-costigliola]

So if I understand correctly it is safe to make new ByteBuddy() a field in SoftProxies instead of creating one everytime in:

private <V> Class<?> createProxy(Class<V> assertClass, ErrorCollector collector) {
    return new ByteBuddy().subclass(assertClass)
                          .method(METHODS_CHANGING_THE_OBJECT_UNDER_TEST)
                          .intercept(MethodDelegation.to(new ProxifyMethodChangingTheObjectUnderTest(this)))
                          .method(ElementMatchers.<MethodDescription> any()
                                                 .and(not(METHODS_CHANGING_THE_OBJECT_UNDER_TEST))
                                                 .and(not(methodsNotToProxy)))
                          .intercept(MethodDelegation.to(collector))
                          .make()
                          .load(assertClass.getClassLoader())
                          .getLoaded();

I'll add .with(TypeValidation.DISABLED) thanks for the tip.

[PascalSchumacher]

Quoting Rafael:

Yes, All Byte Buddy classes that are exposed to a user are fully immutable what makes them thread safe. The reuse of instances, even among different threads is therefore possible and even recommended.

from https://groups.google.com/forum/#!topic/byte-buddy/snuqL4Qp41Q

[testn]

Some of the overhead came from the anonymous class from @SuperCall. It can be eliminated but it will only shave just a few seconds.

[raphw]

I assume a portion of it comes from the deep generics of the assertj classes. cglib has a rather naive approach to generics as they were only patched late into the library. It filters all methods that are marked as bridges. Unfortunately, this has plenty of draw backs. Byte Buddy processes the whole hierarchy and reconstructs the shape from the generic form just like javac. If you want to do it right, there is not much way around it, unfortunately.

[testn]

If you want to squeeze a bit of performance for the startup case, we can simply use method invoke instead of using @SuperCall. It will shave a couple seconds off as it does not have to create a lot of classes.

[joel-costigliola]

@testn how do you replace @SuperCall concretely ? it's unclear to me ...

[joel-costigliola]

As a side note my soft assertions perf tests results:

• 3.9.0 (with cglib) : ~3500ms
• 3.9.1+ : ~9300ms
• 48484331e commit : ~6000ms

Definitely some improvements but as @raphw said I would not expect it to be as in 3.9.0.
I still need to give a try to using Advice.

[testn]

@joel-costigliola try this https://github.com/joel-costigliola/assertj-core/pull/1225

[raphw]

@joel-costigliola I recently wrote a summary on proxying in our times, you might find that interesting: https://mydailyjava.blogspot.no/2018/04/jdk-11-and-proxies-in-world-past.html - This discussion inspired me to add a section on performance.

[joel-costigliola]

thanks guys, your support is great!

[testn]

@joel-costigliola I think I can squeeze a little of performance out further from bytebuddy. I will need to investigate more.

[joel-costigliola]

@testn cool :) I'll wait before looking at your PR, let me know when it is ready.

[raphw]

@joel-costigliola Could you try out Byte Buddy 1.8.5. I had a look at Byte Buddy's method graph compiler which is probably the most complex component and I found some issues with classes that declare a lot of methods within a hierarchy where a hash function did not play out too nicely and where way too many allocations were made in a method-scaled loop.

I assume this might have hit assertj since the assertion classes tend to declare a lot of methods. Thanks!

[joel-costigliola]

Sounds good, will definitely update to 1.8.5.

[joel-costigliola]

I have updated byte buddy to 1.8.5, it did not make a notable on my soft assertions perf tests results, they still run in ~6000ms.

Another unexpected side effect was that it broke Assumptions_assumeThat_Test (and other assumptions tests):

java.lang.IllegalAccessError: tried to access class org.assertj.core.api.Assumptions$AssumptionMethodInterceptor from class org.assertj.core.api.StringAssert$ByteBuddy$eUpmpcml
    at org.assertj.core.api.StringAssert$ByteBuddy$eUpmpcml.isNotEmpty(Unknown Source)
    at org.assertj.core.api.StringAssert$ByteBuddy$eUpmpcml.isNotEmpty(Unknown Source)
    at org.assertj.core.api.assumptions.Assumptions_assumeThat_Test.should_ignore_test_when_one_of_the_assumption_fails(Assumptions_assumeThat_Test.java:36)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
        ....

The test also breaks in 1.8.4 but succeeds in 1.8.3.

@raphw is it a byte buddy bug or are we doing something wrong in Assumptions?
I can try to write a test case reproducing this issue if you want.

[raphw]

@joel-costigliola This is just a side-effect of the work I had to do for supporting Java 11 which AssertJ now does when applying this patch: https://github.com/joel-costigliola/assertj-core/pull/1230

There are still 2 failing tests which seem related to expectations about the stack trace. Could you have a look? The new default class loading strategy is accomondating module encapsulation but is also a bit slower then the previous default. Therefore, this one test failed. I set the class loading strategy explicitly now, see PR.

[joel-costigliola]

Thanks for the patch, I'll fix the stack trace assertions.

[joel-costigliola]

@raphw The tests pass (I guess you have updated the PR), before merging it, I have asked for some clarifications as I'm not super comfortable maintaining this code (I should probably RTFM of byte buddy to understand better your changes).
I have spotted some areas that can be refactored but I'll take care of that.

I have run my perf tests and there is a slight improvement (from ~6000ms to ~5500ms).

[raphw]

I had another look at what can be improved. Can you try with https://github.com/joel-costigliola/assertj-core/pull/1233 ?

[raphw]

I have done some more profiling for the assertj use case, could you try Byte Buddy 1.8.10?

[joel-costigliola]

@raphw the performance is a bit better from ~5500ms to ~5200ms.

Naive question:
Would it be possible/relevant to ignore generics when proxying methods as this is a costly thing to do ?

[testn]

If you care more about the initial load time performance, this can actually reduce the load time down a bit https://github.com/joel-costigliola/assertj-core/pull/1225/files

[testn]

@joel-costigliola look like there are some significant improvements here. Do you plan to cut 3.10 release soon?

[joel-costigliola]

I was actually thinking about it ;-) I just need to see if there are anything easy/worthwhile to add but I'll do a release in the next couple weeks

[joel-costigliola]

Closing this issue as improvements have been made.
We will keep trying improving performance in the next releases.