Page MenuHomePhabricator

celery log level is INFO causing disruption on ORES service
Closed, ResolvedPublic

Description

<godog> looks like it ran out of disk space for a couple of hours until logrotate kicked in, I'm going to stop puppet and redirect celery logs to /srv/log/celery /cc akosiaris halfak Amir1
5:19 PM A<Amir1> Amir Sarabadani godog: Thanks. I take care of it
5:19 PM We probably need to shut up celery
5:20 PM let me check the puppet config
5:20 PM G<godog> Amir1: yeah it is logging like crazy and two almost identical lines

(Times are in UTC+3:30)

Details

Related Gerrit Patches:
operations/puppet : productioncelery: use SyslogIdentifier
mediawiki/services/ores/deploy : masterIncrease loglevel for ores from INFO to WARNING

Event Timeline

Restricted Application added a project: User-Ladsgroup. · View Herald TranscriptSep 25 2016, 2:13 PM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript

Change 312740 had a related patch set uploaded (by Ladsgroup):
Increase loglevel for ores from INFO to WARNING

https://gerrit.wikimedia.org/r/312740

I'm guessing that's the reason behind the flapping in labs too. I get that fixed asap

Some stuff:

1Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,306 INFO:ores.scoring_systems.celery_queue -- Found reverted in 04e15b5f-b7b2-4e3f-a0ff-91ca7523f2dd!
2Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,306: INFO/Worker-51067] Found reverted in 04e15b5f-b7b2-4e3f-a0ff-91ca7523f2dd!
3Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,307 INFO:ores.scoring_systems.celery_queue -- Looking up reverted in 48880220-c585-4913-aa26-8cd06d70bdec
4Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,307: INFO/Worker-51067] Looking up reverted in 48880220-c585-4913-aa26-8cd06d70bdec
5Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,308 INFO:ores.scoring_systems.celery_queue -- Found reverted in 48880220-c585-4913-aa26-8cd06d70bdec!
6Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,308: INFO/Worker-51067] Found reverted in 48880220-c585-4913-aa26-8cd06d70bdec!
7Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,309 INFO:ores.scoring_systems.celery_queue -- Looking up damaging in 4f899cf0-dfed-45ae-bf03-b782dd8449a2
8Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,309: INFO/Worker-51067] Looking up damaging in 4f899cf0-dfed-45ae-bf03-b782dd8449a2
9Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,310 INFO:ores.scoring_systems.celery_queue -- Found damaging in 4f899cf0-dfed-45ae-bf03-b782dd8449a2!
10Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,310: INFO/Worker-51067] Found damaging in 4f899cf0-dfed-45ae-bf03-b782dd8449a2!
11Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,313 INFO:ores.scoring_systems.celery_queue -- Generating a score map for enwiki:{'goodfaith', 'reverted'}:741106290
12Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,313: INFO/Worker-51067] Generating a score map for enwiki:{'goodfaith', 'reverted'}:741106290
13Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,336 INFO:ores.scoring_systems.celery_queue -- Looking up reverted in f1078454-3a41-407b-9698-1b8350259b10
14Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,336: INFO/Worker-51047] Looking up reverted in f1078454-3a41-407b-9698-1b8350259b10
15Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,405 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for enwiki:{'goodfaith', 'reverted'}:741106288
16Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,405: INFO/Worker-51077] Completed generating score map for enwiki:{'goodfaith', 'reverted'}:741106288
17Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,410 INFO:ores.scoring_systems.celery_queue -- Looking up damaging in 3ac9606c-cd55-4538-99ca-f32af52ded3b
18Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,410: INFO/Worker-51077] Looking up damaging in 3ac9606c-cd55-4538-99ca-f32af52ded3b
19Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,411 INFO:ores.scoring_systems.celery_queue -- Found damaging in 3ac9606c-cd55-4538-99ca-f32af52ded3b!
20Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,411: INFO/Worker-51077] Found damaging in 3ac9606c-cd55-4538-99ca-f32af52ded3b!
21Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,470 INFO:ores.scoring_systems.celery_queue -- Found damaging in c5fd98d9-cd86-461a-a01c-aaccfbe1ecdd!
22Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,470: INFO/Worker-51075] Found damaging in c5fd98d9-cd86-461a-a01c-aaccfbe1ecdd!
23Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,533 INFO:ores.scoring_systems.celery_queue -- Found damaging in 2057c575-fb46-4fce-aaf3-95ff7489c580!
24Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,533: INFO/Worker-51064] Found damaging in 2057c575-fb46-4fce-aaf3-95ff7489c580!
25Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,631 INFO:ores.scoring_systems.celery_queue -- Generating a score map for ptwiki:{'goodfaith', 'reverted'}:46802079
26Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,631: INFO/Worker-51080] Generating a score map for ptwiki:{'goodfaith', 'reverted'}:46802079
27Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,659 INFO:ores.scoring_systems.celery_queue -- Generating a score map for viwiki:{'reverted'}:25164886
28Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,659: INFO/Worker-51066] Generating a score map for viwiki:{'reverted'}:25164886
29Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,682 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for viwiki:{'reverted'}:25164886
30Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,682: INFO/Worker-51066] Completed generating score map for viwiki:{'reverted'}:25164886
31Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,705 INFO:ores.scoring_systems.celery_queue -- Generating a score map for viwiki:{'reverted'}:25164887
32Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,705: INFO/Worker-51076] Generating a score map for viwiki:{'reverted'}:25164887
33Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,727 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for viwiki:{'reverted'}:25164887
34Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,727: INFO/Worker-51076] Completed generating score map for viwiki:{'reverted'}:25164887
35Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,772 INFO:ores.scoring_systems.celery_queue -- Generating a score map for viwiki:{'reverted'}:25164889
36Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,772: INFO/Worker-51070] Generating a score map for viwiki:{'reverted'}:25164889
37Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,793 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for viwiki:{'reverted'}:25164889
38Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,793: INFO/Worker-51070] Completed generating score map for viwiki:{'reverted'}:25164889
39Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,838 INFO:ores.scoring_systems.celery_queue -- Found reverted in f1078454-3a41-407b-9698-1b8350259b10!
40Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,838: INFO/Worker-51047] Found reverted in f1078454-3a41-407b-9698-1b8350259b10!
41Sep 25 13:58:10 scb1002 celery[4453]: 2016-09-25 13:58:10,997 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for ptwiki:{'goodfaith', 'reverted'}:46802079
42Sep 25 13:58:10 scb1002 celery[4453]: [2016-09-25 13:58:10,997: INFO/Worker-51080] Completed generating score map for ptwiki:{'goodfaith', 'reverted'}:46802079
43Sep 25 13:58:11 scb1002 celery[4453]: 2016-09-25 13:58:11,184 INFO:ores.scoring_systems.celery_queue -- Looking up damaging in 980da2c0-f292-4277-8387-367502397388
44Sep 25 13:58:11 scb1002 celery[4453]: [2016-09-25 13:58:11,184: INFO/Worker-51059] Looking up damaging in 980da2c0-f292-4277-8387-367502397388
45Sep 25 13:58:11 scb1002 celery[4453]: 2016-09-25 13:58:11,307 INFO:ores.scoring_systems.celery_queue -- Generating a score map for wikidatawiki:{'damaging'}:379862017
46Sep 25 13:58:11 scb1002 celery[4453]: [2016-09-25 13:58:11,307: INFO/Worker-51060] Generating a score map for wikidatawiki:{'damaging'}:379862017
47Sep 25 13:58:11 scb1002 celery[4453]: 2016-09-25 13:58:11,391 INFO:ores.scoring_systems.celery_queue -- Completed generating score map for wikidatawiki:{'damaging'}:379862017
48Sep 25 13:58:11 scb1002 celery[4453]: [2016-09-25 13:58:11,391: INFO/Worker-51060] Completed generating score map for wikidatawiki:{'damaging'}:379862017
49Sep 25 13:58:11 scb1002 celery[4453]: 2016-09-25 13:58:11,562 INFO:ores.scoring_systems.celery_queue -- Looking up goodfaith in 50f6f8af-e3f0-4763-9d95-8c00668f0776
50Sep 25 13:58:11 scb1002 celery[4453]: [2016-09-25 13:58:11,562: INFO/Worker-51078] Looking up goodfaith in 50f6f8af-e3f0-4763-9d95-8c00668f0776

Mentioned in SAL (#wikimedia-labs) [2016-09-25T16:03:12Z] <Amir1> deploying c2ba205 (T146581)

Change 312740 merged by Ladsgroup:
Increase loglevel for ores from INFO to WARNING

https://gerrit.wikimedia.org/r/312740

Mentioned in SAL (#wikimedia-operations) [2016-09-25T16:25:58Z] <Amir1> deploying 9cc2009 on ORES nodes (T146581)

Ladsgroup moved this task from In progress to Done on the User-Ladsgroup board.Sep 25 2016, 4:34 PM
Ladsgroup moved this task from Active to Done on the Scoring-platform-team (Current) board.

Failure ratio in the last six hours:

Halfak closed this task as Resolved.Sep 28 2016, 9:40 PM

Change 313562 had a related patch set uploaded (by Filippo Giunchedi):
celery: use SyslogIdentifier

https://gerrit.wikimedia.org/r/313562

Change 313562 merged by Filippo Giunchedi:
[operations/puppet@production] celery: use SyslogIdentifier

https://gerrit.wikimedia.org/r/313562