honeycombio/beeline-ruby

Installing beeline via rails configure fails during rails bootstrap

Closed this issue · 17 comments

Trying to follow the install guide for rails I did the following, on rails 4.2.11, ruby 2.4.5

bundle add honeycomb-beeline
bundle install
bundle exec rails generate honeycomb REDACTED --dataset warehouser-dev

Attempting to start rails with the generated initializer now results in the following error (I can post the full stack trace if it would be useful but it doesn't look very illuminating):

Exiting
/Users/sethjohnson/.rbenv/versions/2.4.5/lib/ruby/gems/2.4.0/gems/actionpack-4.2.11/lib/action_dispatch/middleware/stack.rb:125:in `assert_index': No such middleware to insert before: Rails::Rack::Logger (RuntimeError)
	from /Users/sethjohnson/.rbenv/versions/2.4.5/lib/ruby/gems/2.4.0/gems/actionpack-4.2.11/lib/action_dispatch/middleware/stack.rb:88:in `insert'

Ok so I know why this happens, we need to choose a point in the middleware stack to insert the beeline middleware. This happens over here. I chose the Rails::Rack::Logger as it is inserted by default with rails and is also involved in instrumenting the application. Unfortunately there doesn't seem to be a way to check for the presence of other middleware while it is being inserted and you can't catch this exception and insert it somewhere else as this happens much later in the start up of rails.

Are you by chance removing it or altering the default middleware setup in someway?

There are a few calls to config.middleware.use I see. We are using https://github.com/rocketjob/rails_semantic_logger; I wonder if that's somehow causing it to fail.

That certainly looks like it would do it, I'll have to have a think about the best way to handle this 🤔

Ironically, semantic logger is there to enforce structured logging of exactly the type I want to emit to honeycomb.

I'm thinking maybe some configuration parameter where you can specify which middleware to insert the honeycomb middleware after might be the way to go. I'l see what I can come up with based on that

I tried moving around the order of gemfile loads which did not resolve the issue but did reveal another gem conflict, this time with rolify (https://github.com/RolifyCommunity/rolify). It looks like they had a similar issue with a different gem (RolifyCommunity/rolify#156 -> metaskills/less-rails#68) that looks like it might be the same basic issue with load_config_initializers hooks. That one it seems can be worked around by changing the gemfile order to install rolify first before honeycomb-beeline.

@sethjohnson-flexe this should be resolved in 1.1.0. You can skip loading the railtie now using the ENV key and then add the middleware somewhere that makes sense for your application. Let me know if you are still having issues

@martin308 Okay, I will try this out.

great, feel free to re open this issue if it doesn't resolve it

@martin308 I am trying to figure out how to verify that I have the middleware installed and functioning. What should I look for in the events/spans to verify this?

If you run bundle exec rake middleware it should show up in there as Honeycomb::Rails::Middleware. In your events and spans it should create a span with name: http_request

Okay, I was able to get this middleware working but it took me a while to figure out where to put the code. In application.rb I had to add it after all other gems are loaded (i.e. Bundler.require(:default, Rails.env) in the default code for rails 4.x). I modified the code from the extension as follows (there's no reason to take out the safety check on client existence I just wanted to make sure it wasn't failing to load due to the client not existing while debugging):

module Honeycomb
  # Automatically capture rack requests and create a trace
  class Railtie < ::Rails::Railtie
    initializer("honeycomb.install_middleware", after: :load_config_initializers) do |app|
      app.config.middleware.use(
          Honeycomb::Rails::Middleware,
          client: Honeycomb.client,
      )
    end
  end
end

@martin308
I wonder if you want to consider changing the integration to install with middleware.use rather than insert_before. I believe this would remove the need to override the integration with the ENV patch (although I think that change seems independently legit as people might not always want all the integrations installed). Is there a particular reason it needs to be installed earlier in the middleware chain rather than at the end?

The problem with using middleware.use is that it will append the middleware to the bottom of the stack. This potentially misses out on a lot of code that runs during the request. The idea behind inserting it near the logger is that this is generally the point where enough of the middleware has run that populates interesting things about the request we might want to include in a span but before any of the potentially interesting middleware that should be included as part of the trace is run

Okay that makes sense. Can you put a little color on what would qualify as potentially interesting middleware? I'd like to make sure I'm capturing valuable data with the implementation I have. I'm looking at https://guides.rubyonrails.org/rails_on_rack.html#configuring-middleware-stack and not sure which of the defaults after logger I would want to capture in a trace. Is ActionDispatch::Callbacks the main one?

for sure! I would say any middleware you have that could be causing additional latency for your service is interesting to look at. Middleware that hits some kind of external service: Rate limiting middleware might talk to redis. User authentication middleware might talk to a DB. Does that help?

Okay, I think I understand. Thanks that's very helpful.