1281810 - "IOError: Socket closed" during publish-job-action

Status: RESOLVED FIXED

(Tree Management :: Treeherder: Infrastructure, defect, P1)

Description

[Ed Morley [:emorley]]

This seems to have suddenly started about 50 mins ago - related to the recent pulse username/password changes?

https://rpm.newrelic.com/accounts/677903/applications/4180461/filterable_errors?tw%5Bend%5D=1466694019&tw%5Bstart%5D=1466683219#/table?top_facet=transactionUiName&primary_facet=transactionUiName&barchart=barchart&filters=%5B%7B%22key%22%3A%22transactionUiName%22%2C%22value%22%3A%22publish-job-action%22%2C%22like%22%3Afalse%7D%5D&_k=nbrkhg

Individual instance:
https://rpm.newrelic.com/accounts/677903/applications/4180461/traced_errors/cb37e0-cafda7ca-3952-11e6-bd66-b82a72d22a14

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/concurrency/base.py", line 131, in start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/concurrency/prefork.py", line 119, in on_start
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/celery/concurrency/asynpool.py", line 401, in __init__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/billiard/pool.py", line 972, in __init__
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/model/tasks.py", line 78, in publish_job_action
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/model/tasks.py", line 37, in get_publisher
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/model/pulse_publisher.py", line 184, in __init__
File "/data/www/treeherder.mozilla.org/treeherder-service/treeherder/model/pulse_publisher.py", line 126, in _generate_publish
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/messaging.py", line 85, in __init__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/messaging.py", line 222, in revive
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/messaging.py", line 105, in declare
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/entity.py", line 171, in declare
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/abstract.py", line 118, in channel
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/utils/__init__.py", line 425, in __call__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/messaging.py", line 209, in <lambda>
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/connection.py", line 757, in default_channel
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/connection.py", line 742, in connection
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/connection.py", line 697, in _establish_connection
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/kombu/transport/pyamqp.py", line 116, in establish_connection
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/amqp/connection.py", line 180, in __init__
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/amqp/abstract_channel.py", line 67, in wait
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/amqp/connection.py", line 241, in _wait_method
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/amqp/connection.py", line 330, in read_timeout
File "/data/www/treeherder.mozilla.org/venv/lib/python2.7/site-packages/amqp/method_framing.py", line 189, in read_method
 exceptions:IOError: Socket closed 

https://github.com/mozilla/treeherder/blob/5d4b9ecb5568b41fc2bf41a261fb28305611adff/treeherder/model/pulse_publisher.py#L118-L127

Comment 1

[Kendall Libby [:fubar] (he/him)]

seems likely. I wonder if it's username mismatch? cam's request in bug 1280526 had the username listed as "treeherder-prod" but in puppet/hiera it's actuall just "treeherder". Related, the password he had listed in that bug didn't match what was in puppet/hiera...  do we have TWO treeherder prod pulse users?

Comment 2

[Ed Morley [:emorley]]

I know we were already using a Pulse account to publish messages _to_ (which is the transaction occurring in this exception). I think the new feature (which was for consuming _from_ Pulse) was being added with its own Pulse account (which may or may not have been intentional).

It's unfortunate that amqp/Kombu doesn't output a nicer message than "Socket closed" if it is indeed a credentials issue.

Comment 3

[Ed Morley [:emorley]]

> (which may or may not have been intentional)

To be more precise:

I believe Cameron meant for the credentials that were being added to puppet/hiera to be kept separate, since I think it's a separate account. Whether we need a separate account is another matter (but I guess sensible?).

Comment 4

[Kendall Libby [:fubar] (he/him)]

difficult to say? on staging, there's only the "treeherder-stage" pulse user and it's used in both PULSE_URI and PULSE_DATA_INGESTION_CONFIG. 

just asked :mcote, and he says the new password he gave me was for "treeherder-prod". I'm going to fix the password for the "treeherder" user (eg PULSE_URI).

Comment 5

[Ed Morley [:emorley]]

Ah yeah I think perhaps we only did the publishing part on prod.

When Cameron's back we will:
* Decide whether two usernames are necessary for each environment, or if we should use one
* Pick more appropriate usernames for each (eg "treeherder-publishing-prod" and "treeherder-ingestion-prod")
* Pick more descriptive environment variable names

...which will hopefully make this less confusing for future password rotations :-)
(I think it's something that should be as easy as possible for eg MOC to do without assistance, in the case of emergencies etc)

Comment 6

[Ed Morley [:emorley]]

Errors have stopped now - thank you.
Bug 1281821 filed for clarifying the username situation.

Comment 7

[Ed Morley [:emorley]]

Unfortunately this is still occurring:
https://rpm.newrelic.com/accounts/677903/applications/4180461/filterable_errors?tw%5Bend%5D=1466776249&tw%5Bstart%5D=1466517049#/table?top_facet=transactionUiName&primary_facet=transactionUiName&barchart=barchart&filters=%5B%7B%22key%22%3A%22transactionUiName%22%2C%22value%22%3A%22publish-job-action%22%2C%22like%22%3Afalse%7D%5D&_k=ev19qu

Any ideas? :-)

Comment 9

[Kendall Libby [:fubar] (he/him)]

not offhand; the credentials on my side are as I left them yesterday (ie the original set). restarted celery_worker_hp.. ("have you turned it off and then back on?") tailing the log to see if more comes in.

any ideas on how to manually test? last I looked at amqp stuff, it seemed fairly complicated to do.

Comment 10

[Kendall Libby [:fubar] (he/him)]

and as I hit 'Save Changes' the log scrolls... a bunch of successful publish-job-action! -.-

Comment 12

[Armen [:armenzg]]

I can confirm that my pulse listener is working again. Thanks!

Comment 13

[Ed Morley [:emorley]]

:-)