Page MenuHomePhabricator
Create Task
Maniphest T146581

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

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

SubjectRepoBranchLines +/-
celery: use SyslogIdentifieroperations/puppetproduction+1 -0
Increase loglevel for ores from INFO to WARNINGmediawiki/services/ores/deploymaster+1 -1
Customize query in gerrit

Related Objects

Event Timeline

Ladsgroup created this task.Sep 25 2016, 2:13 PM
Restricted Application added a project: User-Ladsgroup. · View Herald TranscriptSep 25 2016, 2:13 PM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
Ladsgroup added a subscriber: fgiunchedi.Sep 25 2016, 2:16 PM
Ladsgroup merged a task: T146583: ores celery worker spamming scb logs.Sep 25 2016, 3:05 PM
Ladsgroup moved this task from Incoming to In progress on the User-Ladsgroup board.Sep 25 2016, 3:21 PM
gerritbot subscribed.Sep 25 2016, 3:26 PM

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

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

gerritbot added a project: Patch-For-Review.Sep 25 2016, 3:26 PM
Ladsgroup added a comment.Sep 25 2016, 3:27 PM

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

Ladsgroup added a comment.Sep 25 2016, 3:29 PM

Some stuff:

P4114 Masterwork From Distant Lands
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

Ladsgroup added a comment.Sep 25 2016, 3:48 PM

Also in labs: https://github.com/wiki-ai/ores-wmflabs-deploy/pull/69

Stashbot subscribed.Sep 25 2016, 4:03 PM

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

gerritbot added a comment.Sep 25 2016, 4:22 PM

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

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

Stashbot added a comment.Sep 25 2016, 4:26 PM

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

Ladsgroup mentioned this in rORESDEPLOY9cc20094d62d: Increase loglevel for ores from INFO to WARNING.Sep 25 2016, 4:29 PM
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 Parked to Completed on the Machine-Learning-Team (Active Tasks) board.
Ladsgroup added a comment.Sep 25 2016, 4:39 PM

Failure ratio in the last six hours:

pasted_file (510×806 px, 66 KB)

Halfak closed this task as Resolved.Sep 28 2016, 9:40 PM
gerritbot added a comment.Sep 30 2016, 9:24 AM

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

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

Ladsgroup mentioned this in T147163: ORES disk space monitor.Oct 2 2016, 10:15 PM
greg added a project: Wikimedia-Incident.Oct 4 2016, 3:55 PM
greg moved this task from Active investigation to Follow-up prevention on the Wikimedia-Incident board.
gerritbot added a comment.Jun 1 2017, 3:43 PM

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

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

Krinkle edited projects, added Sustainability (Incident Followup); removed Wikimedia-Incident.Apr 28 2020, 9:50 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits