Since ~10:40 UTC the OCG's Job Queue keep increasing:
More data in https://grafana.wikimedia.org/dashboard/db/ocg
Description
Description
Details
Details
Customize query in gerrit
Related Objects
Related Objects
- Mentioned In
- T144120: "Generation of the document file has failed. Status: Rendering process died with non zero code: 1" for https://en.wikipedia.org/wiki/User:DennisDaniels/Books/Medical_Laboratory_Basics
T97524: ocg alarm ocg_job_status_queue 'flapping' - Mentioned Here
- T150604: Download as PDF does not work in English Wiktionary: "There was an error while attempting to render your book."
rGOCG0bf27e3452df: Add en.wiktionary.org to blacklist temporarily to prevent DoS.
T97030: Collection extension should pass request source and user information to backend for logging
T144120: "Generation of the document file has failed. Status: Rendering process died with non zero code: 1" for https://en.wikipedia.org/wiki/User:DennisDaniels/Books/Medical_Laboratory_Basics
Event Timeline
Comment Actions
Someone is trying to render all of enwiktionary to PDF. At the moment they are up to "unadventurous".
cscott@ocg1001:/srv/deployment/ocg/ocg$ tail -f /var/log/ocg/ocg.log | fgrep enwiktionary
Oct 3 18:59:35 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":2899,"level":30,"channel":"backend.bundler.bin","job":{"id":"acb9c57867b85b6cf8096bbd2904b2861541efac","writer":"rdf2latex"},"msg":"[33%] Fetching parsed articles: enwiktionary:unadulteratedly [complete]","time":"2016-10-03T18:59:35.787Z","v":0}
Oct 3 18:59:35 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":2899,"level":30,"channel":"backend.bundler.bin","job":{"id":"acb9c57867b85b6cf8096bbd2904b2861541efac","writer":"rdf2latex"},"msg":"[73%] Creating attribution page: enwiktionary:<custom wikitext> [Parsoid]","time":"2016-10-03T18:59:35.796Z","v":0}
Oct 3 18:59:35 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":425,"level":30,"channel":"backend.bundler.bin","job":{"id":"029e8c039f6acf99ef7ae1e346e0caf821051929","writer":"rdf2latex"},"msg":"[10%] Fetching wiki configuration: enwiktionary siteinfo","time":"2016-10-03T18:59:35.820Z","v":0}
Oct 3 18:59:35 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":24955,"level":30,"channel":"backend.bundler.bin","job":{"id":"8f5788875e76c0722452b953d3bd5b283e0fac28","writer":"rdf2latex"},"msg":"[28%] Fetching parsed articles: enwiktionary:unadulterously [Parsoid, revision 39056132]","time":"2016-10-03T18:59:35.903Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":425,"level":30,"channel":"backend.bundler.bin","job":{"id":"029e8c039f6acf99ef7ae1e346e0caf821051929","writer":"rdf2latex"},"msg":"[28%] Fetching parsed articles: enwiktionary:unadventurous [Parsoid, revision 31584643]","time":"2016-10-03T18:59:36.009Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":24955,"level":30,"channel":"backend.bundler.bin","job":{"id":"8f5788875e76c0722452b953d3bd5b283e0fac28","writer":"rdf2latex"},"msg":"[30%] Fetching parsed articles: enwiktionary:unadulterously [authors, revision 39056132]","time":"2016-10-03T18:59:36.088Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":24955,"level":30,"channel":"backend.bundler.bin","job":{"id":"8f5788875e76c0722452b953d3bd5b283e0fac28","writer":"rdf2latex"},"msg":"[33%] Fetching parsed articles: enwiktionary:unadulterously [complete]","time":"2016-10-03T18:59:36.149Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":24955,"level":30,"channel":"backend.bundler.bin","job":{"id":"8f5788875e76c0722452b953d3bd5b283e0fac28","writer":"rdf2latex"},"msg":"[73%] Creating attribution page: enwiktionary:<custom wikitext> [Parsoid]","time":"2016-10-03T18:59:36.156Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":425,"level":30,"channel":"backend.bundler.bin","job":{"id":"029e8c039f6acf99ef7ae1e346e0caf821051929","writer":"rdf2latex"},"msg":"[30%] Fetching parsed articles: enwiktionary:unadventurous [authors, revision 31584643]","time":"2016-10-03T18:59:36.262Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":425,"level":30,"channel":"backend.bundler.bin","job":{"id":"029e8c039f6acf99ef7ae1e346e0caf821051929","writer":"rdf2latex"},"msg":"[33%] Fetching parsed articles: enwiktionary:unadventurous [complete]","time":"2016-10-03T18:59:36.381Z","v":0}
Oct 3 18:59:36 ocg1001 mw-ocg-service: {"name":"mw-ocg-service","hostname":"ocg1001","pid":425,"level":30,"channel":"backend.bundler.bin","job":{"id":"029e8c039f6acf99ef7ae1e346e0caf821051929","writer":"rdf2latex"},"msg":"[73%] Creating attribution page: enwiktionary:<custom wikitext> [Parsoid]","time":"2016-10-03T18:59:36.388Z","v":0}Comment Actions
I cleared the queue to make things a little more responsive for others:
cscott@ocg1001:/srv/deployment/ocg/ocg$ sudo -u ocg -g ocg nodejs-ocg mw-ocg-service/scripts/clear-queue.js -c /etc/ocg/mw-ocg-service.js
Going to have to come up with a better solution to rate limit by project or something like that? Or just do a user ban (but first I need to add enough logging to figure out who is responsible).
Comment Actions
@elukey said:
(12:53:51 PM) elukey: cscott: one thing that was noted from https://grafana.wikimedia.org/dashboard/db/eventbus is that EventBus (and ChangeProp) saw a rapid increase in transcludes events ~20 mins after the OCG's queue started to increase (12:54:07 PM) elukey: not sure if related or not (we were thinking about a template change somewhere)
It's probably the attribution pages being rendered in the logs above: OCG renders attributions via template transclusion, to allow wiki admins to edit the exact attribution text and format. So a surge in OCG renders will cause a surge in template transclusions.
Comment Actions
Change 313876 had a related patch set uploaded (by C. Scott Ananian):
Allow administrators to blacklist renders of certain metabooks.
Comment Actions
Change 313876 merged by jenkins-bot:
Allow administrators to blacklist renders of certain metabooks.
Comment Actions
Change 313915 had a related patch set uploaded (by C. Scott Ananian):
Add en.wiktionary.org to blacklist temporarily to prevent DoS.
Comment Actions
Change 313915 merged by C. Scott Ananian:
Add en.wiktionary.org to blacklist temporarily to prevent DoS.
Comment Actions
Mentioned in SAL (#wikimedia-operations) [2016-10-03T21:50:46Z] <cscott> updated OCG to version 0bf27e3452dfdc770317f15793e93e6e89c7865a (T147211, T144120)
Comment Actions
ok, deployed a patch to blacklist en.wiktionary.org for the time being, rejecting jobs in the front end. when the front end error rate on https://grafana.wikimedia.org/dashboard/db/ocg goes back down, we can revert 0bf27e3452dfdc770317f15793e93e6e89c7865a .
The next steps would be to add additional logging to the Collection front end -- IP or username or something like that -- and then we can use a more precise blacklist regexp. We could also try to tackle T97030 while we're at it. The blacklist patch does dump the complete metabook into logstash when it rejects a job, so if we stuff some additional logging into metabook we should be able to get more information about our mystery spider.
Comment Actions
Change 314058 had a related patch set uploaded (by C. Scott Ananian):
Revert "Add en.wiktionary.org to blacklist temporarily to prevent DoS."
Comment Actions
Change 314177 had a related patch set uploaded (by C. Scott Ananian):
Log request source information passed along from PHP.
Comment Actions
Change 314178 had a related patch set uploaded (by C. Scott Ananian):
Pass request source and user information to backend.
Comment Actions
Since the deployment of the last changes, I was looking at disk usage and I noticed that there are a ton of deleted and unclosed files created by ocg in
/srv/deployment/ocg/postmortem/
this happens when a file is unlinked from the filesystem, but its filehandle is still open in the application.
I have no idea if this is a regression introduced by the latest deployment, though.
Comment Actions
I'm guessing that's most likely caused by the actions I took to clear the
queue pre-deploy. But I'll take a look.
Comment Actions
Change 314177 merged by jenkins-bot:
Log request source information passed along from PHP.
Comment Actions
Change 314058 merged by Arlolra:
Revert "Add en.wiktionary.org to blacklist temporarily to prevent DoS."