mirror of
https://github.com/openfoodfoundation/openfoodnetwork
synced 2026-01-24 20:36:49 +00:00
ee94101edd
There's a bunch of logging bits we need to find out what happened in `#5294`, the first of which is logging as we are used to for Rails itself. Turns out we were already logging but the log lines weren't displayed. That's because workers have no access to the Rails logger unless we hack things a bit in the config/initializer. If we want to keep DJ's logs in a different file, which I think is good for debugging purposes, we need to diverge from Rails.logger. However, there's no access to Delayed::Worker.logger in custom job classes either so there's no way other than mimicking that logger's format if we want log lines to be consistent. Now the current logs will see the light like: ``` 2020-05-07T14:09:42+0000: [Worker(host:8dc5e7e6f434 pid:1)] Job SubscriptionPlacementJob (id=54) RUNNING 2020-05-07T14:09:42+0000: Placing Order for Proxy Order 1 2020-05-07T14:09:42+0000: Issue in Subscription Order 2: complete 2020-05-07T14:09:42+0000: Placing Order for Proxy Order 7 2020-05-07T14:09:42+0000: Issue in Subscription Order 3: complete 2020-05-07T14:09:43+0000: [Worker(host:8dc5e7e6f434 pid:1)] Job SubscriptionPlacementJob (id=54) COMPLETED after 0.3378 2020-05-07T14:09:43+0000: [Worker(host:8dc5e7e6f434 pid:1)] 1 jobs processed at 2.8054 j/s, 0 failed ``` We'll see if we need to format these messages differently to make them more greppeable.