ActionSupport Cache integration only recording SET and DELETE operations

[djmb]

Under Rails 6.0.1 we are only seeing SET and DELETE opertations for the ActiveSupport Cache integration.

It looks like it caused by extra methods that are added in Rails' LocalStore implementation - https://github.com/rails/rails/blob/v6.0.1/activesupport/lib/active_support/cache/strategy/local_cache.rb#L53-L79

These are not patched to calls to them are missed. The SET operations that are recorded look to come from increment and decrement calls that do use the patched write method.

[delner]

In this case, what do you expect to see that you're not seeing? GET calls? Something else?

[djmb]

Yes I'd also expect to also see GETs reported. I think as well though that the SET counts are not accurate as they only get triggered by calls to increment and decrement calls and not calls to write.

Looking into this a bit more I think the issue is partly caused because we use the dalli gem and have a rails cache of :dalli_store. This means that the Rails cache is an instance of ActiveSupport::Cache::DalliStore, which doesn't inherit from ActiveSupport::Cache::Store so it doesn't have the Datadog instrumentation.

There is another adapter included in Rails :mem_cache_store that also uses the dalli gem which might work better so I can give that a try, though there doesn't seem to be much clarity on which store you should use (petergoldstein/dalli#557).

Either way there's another issue here - any Rails cache that implements Strategy::LocalCache (which both of those two do) then contains a nested ActiveSupport::Cache::Strategy::LocalCache which is a subclass of ActiveSupport::Cache::Store and is therefore an instrumented, leading to potential double counting of cache calls. This is where the SET and DELETE operations that we do get come from.

Finally ActiveSupport::Cache::Store also has read_multi and write_multi methods which are not instrumented.

[delner]

Okay this is a helpful triage; we'll reassess this instrumentation, see if we can improve upon it. Might follow up later with some questions or updates. Thanks for the heads up @djmb!

[marcotc]

I've spend a some time trying out a few implementations that would work with ActiveSupport::Cache::Strategy::LocalCache but, because LocalCache is prepended into other classes, there's no way to affect all Modules/Classes that use LocalCache through class hierarchy modifications (prepending our own mixins, for example). The only ways to accomplish this intrumention that I found are:

1. Monkey Patch relevant methods in ActiveSupport::Cache::Strategy::LocalCache, the old and dirty way.
2. Add a callback to ActiveSupport::Cache::Strategy::LocalCache.prepended to allow us to interject when LocalCache is prepended. Here's my very WIP attempt at it.
   But we also need to modify all classes that have already prepended LocalCache (which is the most common case, as Rails will already be loaded when Datadog.configure is run). To the best of my knowledge, this requires waking the ObjectSpace looking for those instances.
   Even with these changes, we still have to dynamically create new mixin modules, as most classes that we are trying to now prepend our tracing mixins already have those same mixins higher up the ancestor chain, due to most cache implementations inheriting from ActiveSupport::Cache::Store, which we instrument. Those mixins higher up the chain do not intercept the LocalCache request soon enough, and are completely missed when LocalCache finds a cache hit locally.

Overall, I wasn't able to come up with an implementation that seemed maintainable at this moment.

Regarding instrumenting the missing methods (increment, decrement, etc.), I believe we should move to subscribing to ActiveSupport events from now on, specially for new methods. These events have been supported since Rails 3.0, which is the minimum version of Rails we support, and are named "cache_#{operation}.active_support".

[TonyCTHsu]

👋 @djmb We just released v2.2.0. Give it a try!