Page MenuHomeSoftware Heritage

swh-scheduler-listener container crashes when running for the first time
Closed, MigratedEdits Locked

Description

There seems to be an issue with the initialization of rabbitmq, causing swh-scheduler-listener to crash when it runs for the first time (eg. after docker-compose down -v):

swh-scheduler-listener_1        | Waiting for postgresql to start
swh-scheduler-listener_1        | wait-for-it: waiting for swh-scheduler-db:5432 without a timeout
swh-scheduler-listener_1        | wait-for-it: swh-scheduler-db:5432 is available after 0 seconds
swh-scheduler-listener_1        | wait-for-it: waiting for swh-scheduler:5008 without a timeout
swh-scheduler-listener_1        | wait-for-it: swh-scheduler:5008 is available after 3 seconds
swh-scheduler-listener_1        | Starting the swh-scheduler start-listener
swh-scheduler-listener_1        | wait-for-it: waiting for amqp:5672 without a timeout
swh-scheduler-listener_1        | wait-for-it: amqp:5672 is available after 1 seconds
swh-scheduler-listener_1        | INFO:swh.core.config:Loading config file /scheduler.yml
swh-scheduler-listener_1        | INFO:swh.core.config:Loading config file /scheduler.yml
swh-scheduler-listener_1        | [INFO] swh.core.config -- Loading config file /scheduler.yml
swh-scheduler-listener_1        | INFO:pika.adapters.utils.connection_workflow:Pika version 1.1.0 connecting to ('172.21.0.3', 5672)
swh-scheduler-listener_1        | [INFO] pika.adapters.utils.connection_workflow -- Pika version 1.1.0 connecting to ('172.21.0.3', 5672)
swh-scheduler-listener_1        | INFO:pika.adapters.utils.io_services_utils:Socket connected: <socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('172.21.0.5', 36194), raddr=('172.21.0.3', 5672)>
swh-scheduler-listener_1        | [INFO] pika.adapters.utils.io_services_utils -- Socket connected: <socket.socket fd=7, family=AddressFamily.AF_INET, type=SocketKind.SOCK_STREAM, proto=6, laddr=('172.21.0.5', 36194), raddr=('172.21.0.3', 5672)>
swh-scheduler-listener_1        | INFO:pika.adapters.utils.connection_workflow:Streaming transport linked up: (<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240>, _StreamingProtocolShim: <SelectConnection PROTOCOL transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>).
swh-scheduler-listener_1        | [INFO] pika.adapters.utils.connection_workflow -- Streaming transport linked up: (<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240>, _StreamingProtocolShim: <SelectConnection PROTOCOL transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>).
swh-scheduler-listener_1        | INFO:pika.adapters.utils.connection_workflow:AMQPConnector - reporting success: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | [INFO] pika.adapters.utils.connection_workflow -- AMQPConnector - reporting success: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | INFO:pika.adapters.utils.connection_workflow:AMQPConnectionWorkflow - reporting success: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | [INFO] pika.adapters.utils.connection_workflow -- AMQPConnectionWorkflow - reporting success: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | INFO:pika.adapters.blocking_connection:Connection workflow succeeded: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | [INFO] pika.adapters.blocking_connection -- Connection workflow succeeded: <SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>
swh-scheduler-listener_1        | INFO:pika.adapters.blocking_connection:Created channel=1
swh-scheduler-listener_1        | [INFO] pika.adapters.blocking_connection -- Created channel=1
swh-scheduler-listener_1        | WARNING:pika.channel:Received remote Channel.Close (404): "NOT_FOUND - no exchange 'celeryev' in vhost '/'" on <Channel number=1 OPEN conn=<SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>>
swh-scheduler-listener_1        | [WARNING] pika.channel -- Received remote Channel.Close (404): "NOT_FOUND - no exchange 'celeryev' in vhost '/'" on <Channel number=1 OPEN conn=<SelectConnection OPEN transport=<pika.adapters.utils.io_services_utils._AsyncPlaintextTransport object at 0x7fc3a3fd6240> params=<URLParameters host=amqp port=5672 virtual_host=/ ssl=False>>>
swh-scheduler-listener_1        | Traceback (most recent call last):
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/bin/swh", line 8, in <module>
swh-scheduler-listener_1        |     sys.exit(main())
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/swh/core/cli/__init__.py", line 122, in main
swh-scheduler-listener_1        |     return swh(auto_envvar_prefix="SWH")
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 829, in __call__
swh-scheduler-listener_1        |     return self.main(*args, **kwargs)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 782, in main
swh-scheduler-listener_1        |     rv = self.invoke(ctx)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 1259, in invoke
swh-scheduler-listener_1        |     return _process_result(sub_ctx.command.invoke(sub_ctx))
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 1259, in invoke
swh-scheduler-listener_1        |     return _process_result(sub_ctx.command.invoke(sub_ctx))
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 1066, in invoke
swh-scheduler-listener_1        |     return ctx.invoke(self.callback, **ctx.params)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/core.py", line 610, in invoke
swh-scheduler-listener_1        |     return callback(*args, **kwargs)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/click/decorators.py", line 21, in new_func
swh-scheduler-listener_1        |     return f(get_current_context(), *args, **kwargs)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/swh/scheduler/cli/admin.py", line 66, in listener
swh-scheduler-listener_1        |     listener = get_listener(broker, 'celeryev.listener', scheduler_backend)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/swh/scheduler/celery_backend/pika_listener.py", line 34, in get_listener
swh-scheduler-listener_1        |     routing_key=routing_key)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/pika/adapters/blocking_connection.py", line 2571, in queue_bind
swh-scheduler-listener_1        |     self._flush_output(bind_ok_result.is_ready)
swh-scheduler-listener_1        |   File "/srv/softwareheritage/venv/lib/python3.7/site-packages/pika/adapters/blocking_connection.py", line 1340, in _flush_output
swh-scheduler-listener_1        |     raise self._closing_reason  # pylint: disable=E0702
swh-scheduler-listener_1        | pika.exceptions.ChannelClosedByBroker: (404, "NOT_FOUND - no exchange 'celeryev' in vhost '/'")
docker_swh-scheduler-listener_1 exited with code 1

However, it looks like some other container creates celeryev shortly after, as swh-scheduler-listener works after a restart.

Event Timeline

vlorentz triaged this task as Normal priority.May 6 2020, 11:23 AM
vlorentz created this task.
vlorentz updated the task description. (Show Details)