ruby-on-railsemailruby-on-rails-5ahoy

Open tracking not working with Rails ahoy_email gem

I am using ahoy_email gem in Rails and I am unable to make simple open tracking work, and I don't know how to debug it.

The message record is being generated when email is sent:

#<Ahoy::Message:0x000055592a4bd3a8
 id: 1,
 token: "AVKoHmuT0OxqaQRpMfNoDjzD3ibUltHL",
 to: "augusto@qounter.com",
 user_type: "User",
 user_id: 6,
 mailer: "UserMailer#welcome_email",
 subject: "Bienvendido al Sistema de Facturación de Megacentro",
 sent_at: Thu, 30 Aug 2018 21:35:44 UTC +00:00,
 opened_at: nil,
 clicked_at: nil,
 comprobante_id: nil>

My host config:

config.action_mailer.default_url_options = { host: 'megacentro.devtechperu.com' }

The sent email includes the hidden image:

<body>
  ...
  <img alt=3D"" src=3D"http://megacentro.devtechperu.com/ahoy/messages/AVKo=
HmuT0OxqaQRpMfNoDjzD3ibUltHL/open.gif" width=3D"1" height=3D"1">
</body>
</html>

But when opening the email, the opened_at field remains nil

In order to debug, I have copy pasted the appropriate URL into the browser:

http://megacentro.devtechperu.com/ahoy/messages/AVKo=
HmuT0OxqaQRpMfNoDjzD3ibUltHL/open.gif

with and without https just in case

I always get a 204 response from the server, which would mean that the Ahoy controller is not processing the url, since according to the code it should respond with the gif.

I am using Rails 5.2.1 and Ruby 2.5.1 in Ubuntu 18.04 server.

may it be a bug in latest Rails version? Any pointers towards debugging this would be appreciated.

Edit: looking at the server logs it confirms that the route is not being hit:

I, [2018-08-30T22:11:57.320881 #6906]  INFO -- : [f0912842-0b2c-4314-889b-38d813f1ea24] Started GET "/ahoy/messages/AVKo=HmuT0OxqaQRpMfNoDjzD3ibUlt/open.gif" for 179.6.208.88 at 2018-08-30 22:11:57 +0000
I, [2018-08-30T22:11:57.321749 #6906]  INFO -- : [f0912842-0b2c-4314-889b-38d813f1ea24] Processing by ApplicationController#raise_not_found as GIF
I, [2018-08-30T22:11:57.321799 #6906]  INFO -- : [f0912842-0b2c-4314-889b-38d813f1ea24]   Parameters: {"unmatched_route"=>"ahoy/messages/AVKo=HmuT0OxqaQRpMfNoDjzD3ibUlt/open"}
D, [2018-08-30T22:11:57.608802 #6906] DEBUG -- : [f0912842-0b2c-4314-889b-38d813f1ea24]   User Load (78.3ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2  [["id", 3], ["LIMIT", 1]]
D, [2018-08-30T22:11:57.609440 #6906] DEBUG -- : [f0912842-0b2c-4314-889b-38d813f1ea24] No route matches ahoy/messages/AVKo=HmuT0OxqaQRpMfNoDjzD3ibUlt/open
I, [2018-08-30T22:11:57.609619 #6906]  INFO -- : [f0912842-0b2c-4314-889b-38d813f1ea24] Completed 204 No Content in 288ms (ActiveRecord: 159.9ms)

Edit: this route works fine in development but it raises ActionController::RoutingError in production. Hence the 204, as I rescue from this error with the 204

Solution

  • The issue turned out to be these 2 lines in my routes.rb:

    get '*unmatched_route', to: 'application#raise_not_found' unless Rails.env == "development"
post '*unmatched_route', to: 'application#raise_not_found' unless Rails.env == "development"

    which I use to trap unmatched routes and rescue the errors. The gem's routes were never being hit in production as the unmatched route kicked in first. Removing these solved the issue.