Performance crime: Reflection

Problem statement

Commerce customer with phantom slowness recently asked for help – random API duration spikes.

Introduction – not as easy

Enabling pipeline tracing was not much of use due to:

• Huge amount of records per each operation
• A lot of concurrent blocks executed in parallel

A sole commerce flow API produced over 5.6K lines in log in test environment, which must have landed with extra cost due to observer effect.

ETW was not enabled (no event source provider in compiled code). 99 % of memory snapshot collection attempts caught GC running = leaving heap in non-traversable state.

Load test to find the bending point

The series of ‘lightweight‘ performance tests was launched to find the bending point, memory snapshots were collected along the way. RAM is observed to be overcrowded with reflection trails:

These leftovers remain from ReflectionPipelineBlockRunner – stock mechanism in XC to execute processors/blocks; we’ve seen 5.6K executions in ~15 seconds according to pipeline tracing just for one execution:

Faster block runner with expression trees

Instead of finding method on each go, we can compile it once and use all the way down:

x10 faster invocations with 1/4 of allocated objects:

Why this makes perfect sense?

A large portion of blocks are designed with quit-fast checks, f.e:

if (arg.Entity != null) return arg;

The idea is visible in log-driven profiling since 92% of block executions take <0.1 sec:

It is far more costly to create the block, arrange its execution performance, find the ‘run’ method, and finally return 92% of the times after ‘initial’ check.

What could we observe more from the snapshot?

• The pipeline profiling runs always, but not flushed if config says so.
• Stateless blocks are always created from DI despite might have been reused.

• The is null check produces fresh objects on each go:

• Why on Earth would you have ~15K ReaderWriterLockSlim primitives for just a few API calls?

Summary

The memory snapshot has shown the performance speedup potential. Some gains are made without even enabling ETW which required touching customer code.