ankane/ahoy_email

Open tracking not working. How to debug?

augustosamame opened this issue · 2 comments

Hello. 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 email includes the pixel:

...

3D""

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.

Checking the server logs, I can confirm the message 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

I found the issue, sort of.
My routes.rb had these 2 lines:

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.