Hook into Rails instrumentation for timing

[cheerfulstoic]

In the Rails logs it would be great if it said how much time was spent in Neo4j queries like it shows for ActiveRecord. This repo for MongoDB might provide an example to work from:

https://github.com/tomafro/mongo-rails-instrumentation

It would also be great if we could have instrumentation hooks for New Relic / AppScout / whatever...

[cheerfulstoic]

Asked New Relic about this. They pointed me to these methods:

https://docs.newrelic.com/docs/agents/ruby-agent/frameworks/third-party-instrumentation#h2-Custom-Datastores

[cheerfulstoic]

For the record, here's the Rails initializer that I built:

https://github.com/neo4j-examples/graphgist_portal/blob/master/config/initializers/newrelic.rb

It should cover time spent querying Neo4j as well as reporting slow queries in New Relic. Should be pretty easy to extract into a gem, though at the moment this only covers HTTP requests (as in, not embedded requests. Also, of course, no Bolt yet)

[igorescobar]

@cheerfulstoic It still works? I tried to use it but I can't see anything new on NewRelic dashboard. (Neo4j initializer)

[cheerfulstoic]

@igorescobar Good question. This is probably from before the refactoring of the neo4j-core gem, so some of the events have changed. Here's a modified version which should work (I don't have New Relic at the moment).

if defined?(NewRelic)
  require 'new_relic/agent/datastores'

  module Neo4j
    module Server
      # Re-opening class to add newrelic monitoring
      class CypherSession < Neo4j::Session
        NewRelic::Agent::Datastores.trace self, :_query, 'Neo4j'
      end
    end
  end

  ActiveSupport::Notifications.subscribe('neo4j.core.cypher_query') do |_, start, finish, _id, payload|
    NewRelic::Agent::Datastores.notice_statement(cypher, finish - start)
  end
end

I just changed the event name to neo4j.core.cypher_query

[igorescobar]

@cheerfulstoic Thanks for your help.

I just couldn't make it work.

This section seems to be working now:

ActiveSupport::Notifications.subscribe('neo4j.core.cypher_query') do |_, start, finish, _id, payload|
    NewRelic::Agent::Datastores.notice_statement(payload[:query].cypher, finish - start)
end

ps: notice that I changed the original variable cypher that didn't exist and replace it to payload[:query].cypher

I added a few custom logs to make sure it's being executed and it is... but... I just can't see any data on my Newrelic account. I can see Redis, Postgres but Neo4j just don't appear there.

May there is something wrong with NewRelic? or with this section of the code?

NewRelic::Agent::Datastores.trace self, :_query, 'Neo4j'

Not sure if it is useful but I'm using:

Ruby: 2.4.3p205
Rails: 5.1.5
NewRelic: 4.8.0.341

[cheerfulstoic]

Oh, sorry, I was refactoring in another way and I left the cypher in there. I think it should be payload[:cypher].

Did you try using a debugger like pry inside of the subscribe block? If it breaks then you know that it's working, and then you can examine the different arguments to the block

As to if there's something wrong with new relic: Probably there's nothing wrong with the service, but this code might be based on an older version of the new relic gem (though I don't think it changes all that often because that would be a big change for a lot of people). I think a debugger would be the best way to find out, and failing that contacting their support team.

But if the ActiveSupport::Notifications.subscribe('neo4j.core.cypher_query') isn't working, definitely let me know because that's from the Neo4j.rb gems.

[igorescobar]

Did you try using a debugger like pry inside of the subscribe block? If it breaks then you know that it's working, and then you can examine the different arguments to the block

Yes, the ruby interpreter is passing through this section. I believe the problem lies here:

class CypherSession < Neo4j::Session
  NewRelic::Agent::Datastores.trace self, :_query, 'Neo4j'
end

If you open remove this initializer and start a new rails console you will see that the class Neo4j::Server::CypherSession doesn't exists. And it doesn't exist because it is loaded on-demand when you establish a new connection. So when you require the neo4j-server it will overwrite the monkey patch we did on this initializer and the NewRelic::Agent::Datastores.notice_statement won't be attributed to any transaction so I won't appear on NewRelic.

[cheerfulstoic]

Oh, duh, thank you for helping to make that clearer! Neo4j::Server::CypherSession is the old API class.

It might be that you only need those last three lines in the defined?(NewRelic) block. I would think that would catch any queries and it would be much more future-proof because it's using the ActiveSupport::Notification instrumentation / subscription API to send events.

If not, though, I think the appropriate method to surround would be the queries method under Neo4j::Core::CypherSession::Adaptors::Base:

https://github.com/neo4jrb/neo4j-core/blob/master/lib/neo4j/core/cypher_session/adaptors.rb#L111