867305 - Webpay prod celery tasks are not logging to syslog

Status: RESOLVED FIXED

(Cloud Services :: Operations: Marketplace, task, P1)

Description

[Kumar McMillan [:kumar]]

I was looking for log messages about postbacks which run in a celery task but it looks like we stopped getting them in the syslog files after April 2. This is the last log message:

2013-04-02.bz2:Apr  2 15:30:53 web24.addons.phx1.mozilla.com: [] w.pay.utils:INFO about to notify http://mozpay-catalog.paas.allizom.org/mozpay/postback of notice type 0 :/data/www/marketplace.firefox.com-webpay/webpay/webpay/pay/utils.py:56

I ran the code successfully which would otherwise generate that log message but I see nothing.

Any ideas why the celery daemon is not doing logging? 

Notice how the message above is not actually running on celery. I think celery logging never went to syslog because we activated celery here:

Comment 1

[Kumar McMillan [:kumar]]

This is where we activated celery: http://github.com/mozilla/webpay/commit/e460d5b5784fc6ba443073cf9816e0fc03a6c516 (bug 857314)

Comment 2

[Wil Clouser [:clouserw]]

Rob tried to log a bunch of stuff on -dev's celery today and didn't see anything come through either.  If that's totally unrelated you can ignore, but thought it might help.

Comment 3

[Wil Clouser [:clouserw]]

Jeremy found rsyslog was having trouble resolving hostnames or something on -dev.  He fixed it last night, could also be the same issue here?

Comment 4

[Jason Thomas [:jason]]

https://github.com/mozilla/funfactory/pull/51

kumar | oremj: I pulled it in but I don't want to deal with upgrading funfactory in webpay. I'll patch our local LOGGING to fix it.

Comment 5

[Kumar McMillan [:kumar]]

Does this fix sending logs to celery? I thought it only fixed putting the right hostname in the log file? I couldn't easily hotfix webpay so this is not applied yet. It will be in bug 871860

Comment 6

[Jason Thomas [:jason]]

The problems with syslog were fixed by oremj in Bug 868210 and logs in comment 0 started to reappear in logs.

The log hotfix does just fix the hostname in the logs, but without it is hard to differentiate where the logs are originating from.

[[e-mail]1 05]# bzgrep 'w.pay.utils' *
2013-05-03.bz2:May  3 14:59:12 localhost6.localdomain: [] w.pay.utils:INFO about to notify https://marketplace-dev.allizom.org/services/webpay/postback of notice type 0 :/data/www/marketplace-dev.allizom.org-webpay/webpay/webpay/pay/utils.py:56
2013-05-03.bz2:May  3 14:59:13 localhost6.localdomain: [] w.pay.utils:DEBUG URL https://marketplace-dev.allizom.org/services/webpay/postback responded OK for transaction webpay:307797c9-b03d-4c14-91e5-c1e0de310f32 notification :/data/www/marketplace-dev.allizom.org-webpay/webpay/webpay/pay/utils.py:94
2013-05-03.bz2:May  3 15:06:36 localhost6.localdomain: [] w.pay.utils:INFO about to notify https://marketplace-dev.allizom.org/services/webpay/postback of notice type 0 :/data/www/marketplace-dev.allizom.org-webpay/webpay/webpay/pay/utils.py:56

Comment 7

[Kumar McMillan [:kumar]]

ok, thanks. When will this be applied to webpay production? I don't see a commit in Bug 868210 but I just reproduced the problem in prod and I still do not see celery log notices.

To reproduce, you can load this in a browser on a Firefox OS phone (or Firefox OS Simulator) http://mozpay-catalog.paas.allizom.org/ Tap Buy and tap Continue to simulate.

Comment 8

[Kumar McMillan [:kumar]]

re-opening since the original problem for us was on prod only, not dev

Comment 9

[Jason Thomas [:jason]]

webpay -dev and stage celery logs are reaching syslog, but prod is only writing to console. I am still investigating.

Comment 10

[Jeremy Orem [:oremj]]

Should be fixed in https://github.com/mozilla/webpay/commit/767cf680b51d6a574ce4f9a14572b0024df70db9