1284360 - log parser zlib:error: Error -3 while decompressing: incorrect header check

Status: RESOLVED FIXED

(Tree Management :: Treeherder: Data Ingestion, defect, P1)

Description

[Ed Morley [:emorley]]

https://rpm.newrelic.com/accounts/677903/applications/4180461/traced_errors/4eda72-8d181044-4226-11e6-bd66-b82a72d22a14

project: try
job_guid: 2ec1fcef-90d4-459b-8d5b-d50c49986a5e/0
job_log_id: 32530955
job_log_url: https://queue.taskcluster.net/v1/task/LsH875DURZuNW9UMSZhqXg/runs/0/artifacts/public%2Flogs%2Flive_backing.log

Traceback (most recent call last):
File "/data/www/treeherder.mozilla.org/venv/bin/celery", line 14, in <module>
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/__main__.py", line 30, in main
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/celery.py", line 81, in main
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/celery.py", line 793, in execute_from_commandline
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/base.py", line 311, in execute_from_commandline
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/celery.py", line 785, in handle_argv
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/celery.py", line 717, in execute
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/worker.py", line 179, in run_from_argv
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/base.py", line 274, in __call__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bin/worker.py", line 212, in run
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/worker/__init__.py", line 206, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bootsteps.py", line 123, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bootsteps.py", line 374, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/worker/consumer.py", line 279, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/bootsteps.py", line 123, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/worker/consumer.py", line 838, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/worker/loops.py", line 76, in asynloop
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/async/hub.py", line 340, in create_loop
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/concurrency/asynpool.py", line 420, in _event_process_exit
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 1260, in maintain_pool
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 1252, in _maintain_pool
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 1237, in _repopulate_pool
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/concurrency/asynpool.py", line 415, in _create_worker_process
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 1068, in _create_worker_process
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/process.py", line 137, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/forking.py", line 105, in __init__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/process.py", line 292, in _bootstrap
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 295, in run
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 367, in workloop
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/app/trace.py", line 349, in _fast_trace_task
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/newrelic-2.66.0.49/newrelic/hooks/application_celery.py", line 66, in wrapper
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/app/trace.py", line 438, in __protected_call__
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/workers/task.py", line 28, in inner
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/app/task.py", line 676, in retry
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/utils/__init__.py", line 248, in maybe_reraise
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/workers/task.py", line 20, in inner
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/workers/taskset.py", line 24, in inner
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/log_parser/tasks.py", line 35, in inner
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/log_parser/tasks.py", line 108, in parse_log
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/log_parser/utils.py", line 54, in post_log_artifacts
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/log_parser/utils.py", line 21, in extract_text_log_artifacts
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/log_parser/artifactbuildercollection.py", line 131, in parse
 zlib:error: Error -3 while decompressing: incorrect header check

Comment 1

[Ed Morley [:emorley]]

Reproducible with:

./manage.py test_parse_log "https://queue.taskcluster.net/v1/task/LsH875DURZuNW9UMSZhqXg/runs/0/artifacts/public%2Flogs%2Flive_backing.log"

Comment 2

[Ed Morley [:emorley]]

Will, you know more about the gzipped log handling than I do - I don't suppose you would mind having a look at this? There's a reproducible case in comment 1.

Comment 3

[William Lachance (:wlach)]

I'm getting a 404 error following those instructions now.

My guess is that the log file wasn't gzip compressed for whatever reason before it disappeared. Testing against a random uncompressed file seems to confirm that theory:

./manage.py test_parse_log http://people.mozilla.org/~wlachance/0001-Modal-WIP.patch

We certainly could try to detect this case and throw a more descriptive error message. Or maybe just switch to requests like you've suggested before and ditch the streaming log parsing.

Comment 4

[William Lachance (:wlach)]

(In reply to William Lachance (:wlach) from comment #3)
> We certainly could try to detect this case and throw a more descriptive
> error message. Or maybe just switch to requests like you've suggested before
> and ditch the streaming log parsing.

(I believe requests auto-decompresses gzipped files)

Comment 5

[Ed Morley [:emorley]]

So I think it would be best to fix this upstream, since:
(a) Logs should ideally (if not always) be served gzipped
(b) In this case, there are inconsistencies between different requests to the same (Amazom S3/Cloudfront backed) hosts, so it seems more like an unintentional difference between S3 bucket configs, rather than a design decision.

As such, I've filed bug 1291249 for the Taskcluster team to take a look at the S3 configs.

Comment 6

[Ed Morley [:emorley]]

Bug 1291249 has fixed the taskcluster generic-worker type, and the new AMIs containing the update have just been rolled out.

No errors have occurred since.