Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ActiveJob::Logging::LogSubscriber not being unsubscribed #149

Open
owenbendavies opened this issue Jul 9, 2019 · 1 comment
Open

ActiveJob::Logging::LogSubscriber not being unsubscribed #149

owenbendavies opened this issue Jul 9, 2019 · 1 comment

Comments

@owenbendavies
Copy link

owenbendavies commented Jul 9, 2019

When suppress_app_logs is set ActiveJob still has the default logs so I get double logs, e.g.

2019-04-28T10:11:26.013041+00:00 app[web.1]: {"method":"POST","path":"/contact_me/contact_form","format":"html","controller":"pages","action":"contact_form","status":302,"duration":133.44,"db":0.0,"location":"https://example.com/contact_me","route":"pages#contact_form","request_id":"86359372-4aed-4d8f-8a4c-2b3af98d6985","cf_ray":null,"country":null,"host":"example.com","user_id":"8f5f80bb-ab88-4c3b-ad0b-411845eea23f","user_agent":"Mozilla/5.0","fwd":"192.168.1.1","source":"unknown","tags":["request"],"@timestamp":"2019-04-28T10:11:26.011Z","@version":"1"}
2019-04-28T10:11:26.010396+00:00 app[web.1]: {"job_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","queue_name":"DelayedJob(mailers)","job_class":"ActionMailer::DeliveryJob","job_args":["NotificationsMailer","new_message","deliver_now","gid://cms/Message/3"],"request_id":"86359372-4aed-4d8f-8a4c-2b3af98d6985","cf_ray":null,"country":null,"host":"example.com","user_id":"8f5f80bb-ab88-4c3b-ad0b-411845eea23f","user_agent":"Mozilla/5.0","source":"unknown","tags":["job","enqueue"],"@timestamp":"2019-04-28T10:11:26.009Z","@version":"1"}
2019-04-28T10:11:29.221889+00:00 app[worker.1]: {"message":"2019-04-28T10:11:29+0000: [Worker(host:23c9a41b-5a8b-4337-844f-e964f40c3bfb pid:4)] Job ActionMailer::DeliveryJob [3dfe8830-ac51-479d-90a5-e1b8e83edcde] from DelayedJob(mailers) with arguments: [\"NotificationsMailer\", \"new_message\", \"deliver_now\", {\"_aj_globalid\"=\u003e\"gid://cms/Message/3\"}] (id=181) (queue=mailers) RUNNING","@timestamp":"2019-04-28T10:11:29.221+00:00","@version":"1","severity":"INFO","host":null,"fwd":null,"request_id":null,"tags":["rails"]}
2019-04-28T10:11:29.227308+00:00 app[worker.1]: {"job_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","queue_name":"DelayedJob(mailers)","job_class":"ActionMailer::DeliveryJob","job_args":["NotificationsMailer","new_message","deliver_now","gid://cms/Message/3"],"request_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","source":"unknown","tags":["job","perform_start"],"@timestamp":"2019-04-28T10:11:29.227Z","@version":"1"}
2019-04-28T10:11:30.500933+00:00 app[worker.1]: {"request_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","mailer":"NotificationsMailer","action":"new_message","source":"unknown","tags":["mailer","process"],"@timestamp":"2019-04-28T10:11:30.500Z","@version":"1"}
2019-04-28T10:11:30.792405+00:00 app[worker.1]: {"request_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","mailer":"NotificationsMailer","message_id":null,"from":["[email protected]"],"to":["[email protected]","[email protected]"],"source":"unknown","tags":["mailer","deliver"],"@timestamp":"2019-04-28T10:11:30.790Z","@version":"1"}
2019-04-28T10:11:30.792820+00:00 app[worker.1]: {"job_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","queue_name":"DelayedJob(mailers)","job_class":"ActionMailer::DeliveryJob","job_args":["NotificationsMailer","new_message","deliver_now","gid://cms/Message/3"],"duration":1565.08,"request_id":"3dfe8830-ac51-479d-90a5-e1b8e83edcde","source":"unknown","tags":["job","perform"],"@timestamp":"2019-04-28T10:11:30.792Z","@version":"1"}
2019-04-28T10:11:30.807098+00:00 app[worker.1]: {"message":"2019-04-28T10:11:30+0000: [Worker(host:23c9a41b-5a8b-4337-844f-e964f40c3bfb pid:4)] Job ActionMailer::DeliveryJob [3dfe8830-ac51-479d-90a5-e1b8e83edcde] from DelayedJob(mailers) with arguments: [\"NotificationsMailer\", \"new_message\", \"deliver_now\", {\"_aj_globalid\"=\u003e\"gid://cms/Message/3\"}] (id=181) (queue=mailers) COMPLETED after 1.5846","@timestamp":"2019-04-28T10:11:30.806+00:00","@version":"1","severity":"INFO","host":null,"fwd":null,"request_id":null,"tags":["rails"]}
2019-04-28T10:11:30.811585+00:00 app[worker.1]: {"message":"2019-04-28T10:11:30+0000: [Worker(host:23c9a41b-5a8b-4337-844f-e964f40c3bfb pid:4)] 1 jobs processed at 0.6272 j/s, 0 failed","@timestamp":"2019-04-28T10:11:30.811+00:00","@version":"1","severity":"INFO","host":null,"fwd":null,"request_id":null,"tags":["rails"]}

I have done some digging and in https://github.com/shadabahmed/logstasher/blob/master/lib/logstasher.rb#L44 events reuturns an array of items, but for ActiveJob::Logging::LogSubscriber it returns an empty array.

Unfortunately I'm not quite sure why this is different.

Thank you,
Owen

@piotrb
Copy link

piotrb commented Jan 16, 2020

There is now a cleaner system in Rails 6 (and possibly earlier) to unsub ..

ActiveJob::Logging::LogSubscriber.detach_from(:active_job)

I Imagine the same mechanism can be used for most of the other log subscribers

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants