rabbitmq-container may fail to start before migrations run, causing failures for rare migrations that use RabbitMQ

[E44o]

Hi there,
I use Zulip with docker-compose on a centOS (centos-release-7-6.1810.2.el7.centos.x86_64) host machine. Today I want to update Zulip from 2.0.4-1 to 2.1.1, so I only change the version numbers (docker image version and git version) in the docker-compose.yml file und start docker-compose again. But during the migration, there is an “AMQP Connector” error, again and again. The zulip container doesn't start with this error. I haven’t found any information about this matter during now. Any ideas? Thx!

> Operations to perform:
> zulip_1      |   Apply all migrations: analytics, auth, confirmation, contenttypes, otp_static, otp_totp, sessions, social_django, two_factor, zerver
> zulip_1      | Running migrations:
> zulip_1      |   Applying zerver.0209_user_profile_no_empty_password...2020-01-16 09:58:18.617 ERR  [pika.adapters.utils.io_services_utils] Socket failed to connect: <socket.socket fd=18, family=AddressFamily.AF_INET, type=2049, proto=6, laddr=('172.18.0.6', 57144)>; error=111 (Connection refused)
> zulip_1      | 2020-01-16 09:58:18.619 ERR  [pika.adapters.utils.connection_workflow] TCP Connection attempt failed: ConnectionRefusedError(111, 'Connection refused'); dest=(<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('172.18.0.3', 5672))
> zulip_1      | 2020-01-16 09:58:18.619 ERR  [pika.adapters.utils.connection_workflow] AMQPConnector - reporting failure: AMQPConnectorSocketConnectError: ConnectionRefusedError(111, 'Connection refused')
> zulip_1      | 2020-01-16 09:58:18.620 ERR  [pika.adapters.utils.connection_workflow] AMQP connection workflow failed: AMQPConnectionWorkflowFailed: 1 exceptions in all; last exception - AMQPConnectorSocketConnectError: ConnectionRefusedError(111, 'Connection refused'); first exception - None.
> zulip_1      | 2020-01-16 09:58:18.620 ERR  [pika.adapters.utils.connection_workflow] AMQPConnectionWorkflow - reporting failure: AMQPConnectionWorkflowFailed: 1 exceptions in all; last exception - AMQPConnectorSocketConnectError: ConnectionRefusedError(111, 'Connection refused'); first exception - None
> zulip_1      | 2020-01-16 09:58:18.621 ERR  [pika.adapters.blocking_connection] Connection workflow failed: AMQPConnectionWorkflowFailed: 1 exceptions in all; last exception - AMQPConnectorSocketConnectError: ConnectionRefusedError(111, 'Connection refused'); first exception - None
> zulip_1      | 2020-01-16 09:58:18.621 ERR  [pika.adapters.blocking_connection] Error in _create_connection().
> zulip_1      | Traceback (most recent call last):
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/pika/adapters/blocking_connection.py", line 450, in _create_connection
> zulip_1      |     raise self._reap_last_connection_workflow_error(error)
> zulip_1      | pika.exceptions.AMQPConnectionError
> zulip_1      | Traceback (most recent call last):
> zulip_1      |   File "/home/zulip/deployments/current/manage.py", line 46, in <module>
> zulip_1      |     execute_from_command_line(sys.argv)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/core/management/__init__.py", line 364, in execute_from_command_line
> zulip_1      |     utility.execute()
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/core/management/__init__.py", line 356, in execute
> zulip_1      |     self.fetch_command(subcommand).run_from_argv(self.argv)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/core/management/base.py", line 283, in run_from_argv
> zulip_1      |     self.execute(*args, **cmd_options)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/core/management/base.py", line 330, in execute
> zulip_1      |     output = self.handle(*args, **options)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/core/management/commands/migrate.py", line 204, in handle
> zulip_1      |     fake_initial=fake_initial,
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/db/migrations/executor.py", line 115, in migrate
> zulip_1      |     state = self._migrate_all_forwards(state, plan, full_plan, fake=fake, fake_initial=fake_initial)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/db/migrations/executor.py", line 145, in _migrate_all_forwards
> zulip_1      |     state = self.apply_migration(state, migration, fake=fake, fake_initial=fake_initial)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/db/migrations/executor.py", line 244, in apply_migration
> zulip_1      |     state = migration.apply(state, schema_editor)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/db/migrations/migration.py", line 129, in apply
> zulip_1      |     operation.database_forwards(self.app_label, schema_editor, old_state, project_state)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/django/db/migrations/operations/special.py", line 193, in database_forwards
> zulip_1      |     self.code(from_state.apps, schema_editor)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/migrations/0209_user_profile_no_empty_password.py", line 200, in ensure_no_empty_passwords
> zulip_1      |     reset_user_api_key(user_profile)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/migrations/0209_user_profile_no_empty_password.py", line 219, in reset_user_api_key
> zulip_1      |     queue_json_publish("deferred_work", event)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/lib/queue.py", line 332, in queue_json_publish
> zulip_1      |     get_queue_client().json_publish(queue_name, event)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/lib/queue.py", line 315, in get_queue_client
> zulip_1      |     queue_client = SimpleQueueClient()
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/lib/queue.py", line 35, in __init__
> zulip_1      |     self._connect()
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zerver/lib/queue.py", line 39, in _connect
> zulip_1      |     self.connection = pika.BlockingConnection(self._get_parameters())
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/pika/adapters/blocking_connection.py", line 359, in __init__
> zulip_1      |     self._impl = self._create_connection(parameters, _impl_class)
> zulip_1      |   File "/home/zulip/deployments/2020-01-16-09-40-55/zulip-py3-venv/lib/python3.5/site-packages/pika/adapters/blocking_connection.py", line 450, in _create_connection
> zulip_1      |     raise self._reap_last_connection_workflow_error(error)
> zulip_1      | pika.exceptions.AMQPConnectionError
> zulip_1      | Zulip migration failed with exit code 1. Exiting.
> 

[timabbott]

I haven't seen an error in this migration before, but it's clearly an issue with the Zulip container being unable to connect to the rabbitmq container while this migration (which writes to rabbitmq) is running. Was the rabbitmq container up and running at the time migrations were being run?

Can you try logging into the upgraded system and running manage.py migrate manually once RabbitMQ is up?

[E44o]

Thanks for the answer! That’s it.
First I built in your docker-compose file change from yesterday. Than I started the zulip container after the rabbitmq container was online. The migration started automatically. By trying to start the migration manually, the script says: No migrations to apply.
Now it works fine!

[timabbott]

OK. That means the issue here is that we'd ideally have code to wait for the rabbitmq container to be up before the Zulip container runs migrations (to run this particular migration; other migrations won't have this issue as they don't access RabbitMQ). I'm not sure if there's an easy way to add such a wait, but it seems like it might be a good general patch to add.

[cruscio]

Encountered this today, trying to upgrade from v4 to v5. After it failed, I started rabbitmq: docker start docker-zulip_rabbitmq_1, waited a few seconds, and then docker-compose up again - with that, it appears to complete successfully. Looks like the migration script could use a ready wait/check if/when it has dependencies.

[timabbott]

It's hard to have individual migrations wait for their dependencies. I think ideally we'd have some way to have the Docker image wait until RabbitMQ is confirmed up before starting running the zulip container startup jobs?

Probably very low priority, in that we've only used RabbitMQ in migrations a couple times.