Performance change of Protocols reflection in Elixir v1.11

@josevalim maybe you know?

I think having exact line we suspect is useful - mongodb/lib/bson/encoder.ex at 21037d700fc8e9675d99b1d3c6b58ade2f6b61bb · elixir-mongo/mongodb · GitHub

Other interesting detail is that impl_for on v.1.10.4 costs a lot when it returns false (no implementation found).
In case when it returns true performance is almost equal to the v1.11 impl_for version.

However in elixir v.1.11 impl_for works always fast regardless if implementation was found or not.

70ms for a single impl_for lookup? something else is amiss, how are you measuring this?

deadtrickster provided the link above to point where exact impl_for happens. Hope it can give some context.

70ms for a single impl_for lookup?

And it was not the worst case. I tried more series (~2k calls with different datatypes) and some series showed 100ms+ average.
However as I mentioned above it works that slow only when the protocol implementation is not found.
When implementation present (for Map) it works pretty fast, in 90% of cases it takes less then 20 microseconds.

how are you measuring this?

Just with

    start = :erlang.system_time(:microsecond)
    check = Mongo.Encoder.impl_for(value)
    :erlang.system_time(:microsecond) - start

AFAIK we didn’t change anything around this so, if I had to guess, you are having an issue with protocol consolidation on previous versions. Perhaps the protocol was not consolidated for some reason?

thanks, i took 70ms as milliseconds, microseconds commonly abbreviated us.

I’m guessing measuring wall time around a single statement is susceptible, to context switch or other cpu/system activity. Maybe someone can suggest a better way to benchmark this.

You can use benchfella or benchee for example if you need more “accurate” results.

You right!
I’ve checked it with Protocol.consolidated?/1 and it returned false on v1.10.4 version but true on v.1.11

But what is the reason of such behaviour?

I’ve set consolidate_protocols: true explicitly both for mongodb and the project where I use it as a dependency.

On both versions Elixir.Mongo.Encoder.beam was present into consolidated app directory (_build/**/lib/**/consolidated/), but Elixir.Mongo.Encoder.Map.beam presented in _build/**/lib/mongodb/ebin/ only on v1.11

I mean exactly ~70ms (~70000 microseconds).