New version has error in connection

AminAlizadeh-m commented 3 years ago

Hi About 6 hours ago, when the new version was published, I had a connection problem. And the RabbitMQ connection is automatically disconnected! error status code is 406 Closing Channels

TheServat commented 3 years ago

I'm using nestjs and has same problme

jwalton commented 3 years ago

Can you please post a test case that recreates the problem, or at a minimum post some details about what you're passing to connect()? There are integration tests that connect to a rabbitMQ instance, so connections are definitely working in the common use case.

AminAlizadeh-m commented 3 years ago

I use nestjs with transport RMQ and with default settings and just my durable option is false. This is my client proxy. I have many microservice that use RMQ to connect and integration with microservices. All my microservices run with docker in my server.

jwalton commented 3 years ago

@AminAlizadeh-m I tried cloning this repo:

https://github.com/rengthp/nestjs-rabbitmq-microservice

And then I did:

cd microservices-app
npm install
npm install amqp-connection-manager@3.4.3
npm start

I had to go into RabbitMQ and create the "hello" virtual host (as described here), but the app comes up and connects to RabbitMQ just fine.

Can you post your transport options and the URL you're connecting to?

EricWasTakenMJD commented 3 years ago

Hi, Having the same issue where I need to pass connectionOptions to my server so I can pass a CA like this. I connect via AMQPS and port 5671 and I need to pass ca into amqplib so I can use a self-signed cert.

My config, which I pass into node-amqp-connection-manager, looks something like this:

  amqp_opts: {
    heartbeatIntervalInSeconds: 5, 
    reconnectTimeInSeconds: 5, 
    connectionOptions: {
      ca: [fs.readFileSync( __dirname + '/' + secrets.amqpCACertName || 'ca_certificate.pem')],
    },
  },

I believe the issue is that connectionOptions from the node-amqp-connection-manager options object is not actually being passed into AMQPLIB. See the issue where I blamed the specific line: https://github.com/jwalton/node-amqp-connection-manager/issues/173

TrejGun commented 3 years ago

@jwalton you can test on my repo https://github.com/TrejGun/hot-potato-using-nestjs-microservices

jwalton commented 3 years ago

@TrejGun - Your repo connects to RabbitMQ for me. You can see a couple of ECONNREFUSED while Rabbit is coming up, but it works fine otherwise:

Log

$ docker-compose up
Creating network "hot-potato-using-nestjs-microservices_default" with the default driver
Creating hot-potato-using-nestjs-microservices_hot-potato_1 ... done
Creating rabbitmq                                           ... done
Creating hot-potato-player2                                 ... done
Creating hot-potato-api                                     ... done
Creating hot-potato-player3                                 ... done
Creating hot-potato-player1                                 ... done
Attaching to hot-potato-using-nestjs-microservices_hot-potato_1, rabbitmq, hot-potato-api, hot-potato-player1, hot-potato-player3, hot-potato-player2
hot-potato-using-nestjs-microservices_hot-potato_1 exited with code 0
hot-potato-api |
hot-potato-api | > @hot-potato-using-nestjs-microservices/api@0.0.1 start
hot-potato-api | > NODE_ENV=development tsc-watch --onSuccess "node ." --onFailure "echo Compilation Failed"
hot-potato-api |
hot-potato-player1 |
hot-potato-player1 | > @hot-potato-using-nestjs-microservices/player@0.0.1 start
hot-potato-player1 | > NODE_ENV=development tsc-watch --onSuccess "node ." --onFailure "echo Compilation Failed"
hot-potato-player1 |
hot-potato-player3 |
hot-potato-player3 | > @hot-potato-using-nestjs-microservices/player@0.0.1 start
hot-potato-player3 | > NODE_ENV=development tsc-watch --onSuccess "node ." --onFailure "echo Compilation Failed"
hot-potato-player3 |
hot-potato-player2 |
hot-potato-player2 | > @hot-potato-using-nestjs-microservices/player@0.0.1 start
hot-potato-player2 | > NODE_ENV=development tsc-watch --onSuccess "node ." --onFailure "echo Compilation Failed"
hot-potato-player2 |
hot-potato-api |
12:36:05 PM - Starting compilation in watch mode...
hot-potato-api |
hot-potato-player1 |
12:36:06 PM - Starting compilation in watch mode...
hot-potato-player1 |
hot-potato-player3 |
12:36:06 PM - Starting compilation in watch mode...
hot-potato-player3 |
hot-potato-player2 |
12:36:06 PM - Starting compilation in watch mode...
hot-potato-player2 |
rabbitmq      | 2021-08-26 12:36:10.059251+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:10.177498+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:10.177634+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:10.177691+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:10.177756+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:10.178029+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:10.178105+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:10.178176+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:11.807751+00:00 [noti] <0.44.0> Application syslog exited with reason: stopped
rabbitmq      | 2021-08-26 12:36:11.807920+00:00 [noti] <0.222.0> Logging: switching to configured handler(s); following messages may not be visible in this log output
rabbitmq      | 2021-08-26 12:36:11.872845+00:00 [noti] <0.222.0> Logging: configured log handlers are now ACTIVE
rabbitmq      | 2021-08-26 12:36:12.685114+00:00 [info] <0.222.0> ra: starting system quorum_queues
rabbitmq      | 2021-08-26 12:36:12.685337+00:00 [info] <0.222.0> starting Ra system: quorum_queues in directory: /var/lib/rabbitmq/mnesia/rabbit@3389c4367da7/quorum/rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:13.024407+00:00 [info] <0.260.0> ra: meta data store initialised for system quorum_queues. 0 record(s) recovered
rabbitmq      | 2021-08-26 12:36:13.107382+00:00 [noti] <0.265.0> WAL: ra_log_wal init, open tbls: ra_log_open_mem_tables, closed tbls: ra_log_closed_mem_tables
rabbitmq      | 2021-08-26 12:36:13.129221+00:00 [info] <0.222.0> ra: starting system coordination
rabbitmq      | 2021-08-26 12:36:13.129291+00:00 [info] <0.222.0> starting Ra system: coordination in directory: /var/lib/rabbitmq/mnesia/rabbit@3389c4367da7/coordination/rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:13.140020+00:00 [info] <0.273.0> ra: meta data store initialised for system coordination. 0 record(s) recovered
rabbitmq      | 2021-08-26 12:36:13.140541+00:00 [noti] <0.278.0> WAL: ra_coordination_log_wal init, open tbls: ra_coordination_log_open_mem_tables, closed tbls: ra_coordination_log_closed_mem_tables
rabbitmq      | 2021-08-26 12:36:13.152748+00:00 [info] <0.222.0>
rabbitmq      | 2021-08-26 12:36:13.152748+00:00 [info] <0.222.0>  Starting RabbitMQ 3.9.4 on Erlang 24.0.5 [jit]
rabbitmq      | 2021-08-26 12:36:13.152748+00:00 [info] <0.222.0>  Copyright (c) 2007-2021 VMware, Inc. or its affiliates.
rabbitmq      | 2021-08-26 12:36:13.152748+00:00 [info] <0.222.0>  Licensed under the MPL 2.0. Website: https://rabbitmq.com
rabbitmq      |
rabbitmq      |   ##  ##      RabbitMQ 3.9.4
rabbitmq      |   ##  ##
rabbitmq      |   ##########  Copyright (c) 2007-2021 VMware, Inc. or its affiliates.
rabbitmq      |   ######  ##
rabbitmq      |   ##########  Licensed under the MPL 2.0. Website: https://rabbitmq.com
rabbitmq      |
rabbitmq      |   Erlang:      24.0.5 [jit]
rabbitmq      |   TLS Library: OpenSSL - OpenSSL 1.1.1l  24 Aug 2021
rabbitmq      |
rabbitmq      |   Doc guides:  https://rabbitmq.com/documentation.html
rabbitmq      |   Support:     https://rabbitmq.com/contact.html
rabbitmq      |   Tutorials:   https://rabbitmq.com/getstarted.html
rabbitmq      |   Monitoring:  https://rabbitmq.com/monitoring.html
rabbitmq      |
rabbitmq      |   Logs: /var/log/rabbitmq/rabbit@3389c4367da7_upgrade.log
rabbitmq      |         
rabbitmq      |
rabbitmq      |   Config file(s): /etc/rabbitmq/conf.d/10-default-guest-user.conf
rabbitmq      |                   /etc/rabbitmq/conf.d/management_agent.disable_metrics_collector.conf
rabbitmq      |
rabbitmq      |   Starting broker...2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  node           : rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  home dir       : /var/lib/rabbitmq
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  config file(s) : /etc/rabbitmq/conf.d/10-default-guest-user.conf
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>                 : /etc/rabbitmq/conf.d/management_agent.disable_metrics_collector.conf
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  cookie hash    : x8tGmsc51J84BDnD/G/O+A==
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  log(s)         : /var/log/rabbitmq/rabbit@3389c4367da7_upgrade.log
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>                 : 
rabbitmq      | 2021-08-26 12:36:13.158940+00:00 [info] <0.222.0>  database dir   : /var/lib/rabbitmq/mnesia/rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:13.546858+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:13.547007+00:00 [info] <0.222.0> Feature flags:   [ ] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:13.547058+00:00 [info] <0.222.0> Feature flags:   [ ] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:13.553585+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:13.553654+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:13.553908+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:13.553946+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:13.553981+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:13.554015+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:13.554424+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-player3 |
hot-potato-player3 | 12:36:20 PM - Found 0 errors. Watching for file changes.
hot-potato-player1 |
hot-potato-player1 | 12:36:20 PM - Found 0 errors. Watching for file changes.
hot-potato-api |
hot-potato-api | 12:36:20 PM - Found 0 errors. Watching for file changes.
hot-potato-player2 |
hot-potato-player2 | 12:36:20 PM - Found 0 errors. Watching for file changes.
rabbitmq      | 2021-08-26 12:36:22.379634+00:00 [info] <0.222.0> Running boot step pre_boot defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.379715+00:00 [info] <0.222.0> Running boot step rabbit_global_counters defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.380473+00:00 [info] <0.222.0> Running boot step rabbit_osiris_metrics defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.380674+00:00 [info] <0.222.0> Running boot step rabbit_core_metrics defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.381933+00:00 [info] <0.222.0> Running boot step rabbit_alarm defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.396244+00:00 [info] <0.293.0> Memory high watermark set to 795 MiB (833871872 bytes) of 1988 MiB (2084679680 bytes) total
rabbitmq      | 2021-08-26 12:36:22.410847+00:00 [info] <0.295.0> Enabling free disk space monitoring
rabbitmq      | 2021-08-26 12:36:22.410923+00:00 [info] <0.295.0> Disk free limit set to 50MB
rabbitmq      | 2021-08-26 12:36:22.419926+00:00 [info] <0.222.0> Running boot step code_server_cache defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.420785+00:00 [info] <0.222.0> Running boot step file_handle_cache defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.421479+00:00 [info] <0.298.0> Limiting to approx 1048479 file handles (943629 sockets)
rabbitmq      | 2021-08-26 12:36:22.423320+00:00 [info] <0.299.0> FHC read buffering: OFF
rabbitmq      | 2021-08-26 12:36:22.423637+00:00 [info] <0.299.0> FHC write buffering: ON
rabbitmq      | 2021-08-26 12:36:22.427952+00:00 [info] <0.222.0> Running boot step worker_pool defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.428122+00:00 [info] <0.280.0> Will use 6 processes for default worker pool
rabbitmq      | 2021-08-26 12:36:22.428174+00:00 [info] <0.280.0> Starting worker pool 'worker_pool' with 6 processes in it
rabbitmq      | 2021-08-26 12:36:22.429927+00:00 [info] <0.222.0> Running boot step database defined by app rabbit
rabbitmq      | 2021-08-26 12:36:22.432161+00:00 [info] <0.222.0> Node database directory at /var/lib/rabbitmq/mnesia/rabbit@3389c4367da7 is empty. Assuming we need to join an existing cluster or initialise from scratch...
rabbitmq      | 2021-08-26 12:36:22.432261+00:00 [info] <0.222.0> Configured peer discovery backend: rabbit_peer_discovery_classic_config
rabbitmq      | 2021-08-26 12:36:22.432306+00:00 [info] <0.222.0> Will try to lock with peer discovery backend rabbit_peer_discovery_classic_config
rabbitmq      | 2021-08-26 12:36:22.432435+00:00 [info] <0.222.0> All discovered existing cluster peers:
rabbitmq      | 2021-08-26 12:36:22.432477+00:00 [info] <0.222.0> Discovered no peer nodes to cluster with. Some discovery backends can filter nodes out based on a readiness criteria. Enabling debug logging might help troubleshoot.
rabbitmq      | 2021-08-26 12:36:22.437014+00:00 [noti] <0.44.0> Application mnesia exited with reason: stopped
rabbitmq      | 2021-08-26 12:36:22.647565+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:22.647961+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:22.660518+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:22.660786+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:22.660978+00:00 [info] <0.222.0> Feature flag `drop_unroutable_metric`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:22.661144+00:00 [info] <0.222.0> Feature flag `drop_unroutable_metric`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:22.662469+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.662529+00:00 [info] <0.222.0> Feature flags:   [~] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.662593+00:00 [info] <0.222.0> Feature flags:   [ ] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.662638+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.662891+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.662929+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.663044+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.663103+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.663256+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.663401+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.676595+00:00 [info] <0.222.0> Feature flag `drop_unroutable_metric`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:22.678632+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.678725+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.678774+00:00 [info] <0.222.0> Feature flags:   [ ] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.678808+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.678843+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.678878+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.678904+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.679018+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.679052+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.679084+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.692388+00:00 [info] <0.222.0> Feature flag `empty_basic_get_metric`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:22.692514+00:00 [info] <0.222.0> Feature flag `empty_basic_get_metric`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:22.694698+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.694858+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.694946+00:00 [info] <0.222.0> Feature flags:   [~] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.695161+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.695436+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.695553+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.695599+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.696048+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.696103+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.696168+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.721390+00:00 [info] <0.222.0> Feature flag `empty_basic_get_metric`: mark as enabled=true
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [NestFactory] Starting Nest application...
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [NestFactory] Starting Nest application...
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [NestFactory] Starting Nest application...
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [NestFactory] Starting Nest application...
rabbitmq      | 2021-08-26 12:36:22.750456+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.750518+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.750669+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.750709+00:00 [info] <0.222.0> Feature flags:   [ ] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.750742+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.750834+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.750884+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.750918+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.750957+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.751038+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.786000+00:00 [info] <0.222.0> Feature flag `implicit_default_bindings`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:22.786190+00:00 [info] <0.222.0> Feature flag `implicit_default_bindings`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:22.787646+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.787734+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.787766+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.787893+00:00 [info] <0.222.0> Feature flags:   [~] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.788119+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.788589+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.788985+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.789124+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.789367+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.789422+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] AppModule dependencies initialized +112ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HttpModule dependencies initialized +2ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] ApplicationModule dependencies initialized +109ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] PotatoModule dependencies initialized +2ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] TerminusModule dependencies initialized +2ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HttpModule dependencies initialized +4ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HealthModule dependencies initialized +1ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] PotatoModule dependencies initialized +2ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] TerminusModule dependencies initialized +1ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HealthModule dependencies initialized +1ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] ApplicationModule dependencies initialized +127ms
rabbitmq      | 2021-08-26 12:36:22.812058+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 0 retries left
rabbitmq      | 2021-08-26 12:36:22.812494+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:22.812561+00:00 [info] <0.222.0> Feature flag `implicit_default_bindings`: mark as enabled=true
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HttpModule dependencies initialized +5ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] PotatoModule dependencies initialized +2ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] TerminusModule dependencies initialized +3ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HealthModule dependencies initialized +1ms
rabbitmq      | 2021-08-26 12:36:22.820035+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.820175+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.820218+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.820248+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.820284+00:00 [info] <0.222.0> Feature flags:   [ ] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.820318+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.820364+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.820400+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.820435+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.820535+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] ApplicationModule dependencies initialized +147ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HttpModule dependencies initialized +3ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] PotatoModule dependencies initialized +2ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] TerminusModule dependencies initialized +2ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:22 PM     LOG [InstanceLoader] HealthModule dependencies initialized +2ms
rabbitmq      | 2021-08-26 12:36:22.853056+00:00 [info] <0.222.0> Feature flag `maintenance_mode_status`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:22.853198+00:00 [info] <0.222.0> Feature flag `maintenance_mode_status`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:22.854768+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.854845+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.855028+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.855117+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.855169+00:00 [info] <0.222.0> Feature flags:   [~] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.855212+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.855242+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.855274+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.855420+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.855523+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.870632+00:00 [info] <0.222.0> Creating table rabbit_node_maintenance_states for feature flag `maintenance_mode_status`
rabbitmq      | 2021-08-26 12:36:22.885237+00:00 [info] <0.222.0> Feature flag `maintenance_mode_status`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:22.895999+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.896119+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.896199+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.896242+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.896283+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.896315+00:00 [info] <0.222.0> Feature flags:   [ ] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.896370+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.896414+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.896450+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.896496+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.912892+00:00 [info] <0.222.0> Feature flag `quorum_queue`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:22.913015+00:00 [info] <0.222.0> Feature flag `quorum_queue`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:22.914594+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:22.914738+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:22.914785+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:22.914821+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:22.914887+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:22.914934+00:00 [info] <0.222.0> Feature flags:   [~] quorum_queue
rabbitmq      | 2021-08-26 12:36:22.915074+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:22.915219+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:22.915423+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:22.915491+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:22.932082+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:22.932373+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:22.932411+00:00 [info] <0.222.0> Feature flag `quorum_queue`:   migrating Mnesia table rabbit_queue...
rabbitmq      | 2021-08-26 12:36:22.972155+00:00 [info] <0.222.0> Feature flag `quorum_queue`:   migrating Mnesia table rabbit_durable_queue...
rabbitmq      | 2021-08-26 12:36:23.019766+00:00 [info] <0.222.0> Feature flag `quorum_queue`:   Mnesia tables migration done
rabbitmq      | 2021-08-26 12:36:23.019848+00:00 [info] <0.222.0> Feature flag `quorum_queue`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:23.026236+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.026337+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.026423+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.026495+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.026539+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.026683+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.026873+00:00 [info] <0.222.0> Feature flags:   [ ] stream_queue
rabbitmq      | 2021-08-26 12:36:23.026979+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:23.027026+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.027220+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:23.039772+00:00 [info] <0.222.0> Feature flag `stream_queue`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:23.040007+00:00 [info] <0.222.0> Feature flag `stream_queue`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:23.045724+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.046168+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.046233+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.046264+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.046299+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.046323+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.046354+00:00 [info] <0.222.0> Feature flags:   [~] stream_queue
rabbitmq      | 2021-08-26 12:36:23.046384+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:23.046449+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.046472+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:23 PM    WARN [NestApplication] DEPRECATED! "startAllMicroservicesAsync" method is deprecated and will be removed in the next major release. Please, use "startAllMicroservices" instead. +254ms
rabbitmq      | 2021-08-26 12:36:23.063137+00:00 [info] <0.222.0> Feature flag `stream_queue`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:23.068571+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.068677+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.068731+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.068773+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.068803+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.068831+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.069013+00:00 [info] <0.222.0> Feature flags:   [x] stream_queue
rabbitmq      | 2021-08-26 12:36:23.069191+00:00 [info] <0.222.0> Feature flags:   [ ] user_limits
rabbitmq      | 2021-08-26 12:36:23.069365+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.069691+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:23 PM    WARN [NestApplication] DEPRECATED! "startAllMicroservicesAsync" method is deprecated and will be removed in the next major release. Please, use "startAllMicroservices" instead. +252ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:23 PM    WARN [NestApplication] DEPRECATED! "startAllMicroservicesAsync" method is deprecated and will be removed in the next major release. Please, use "startAllMicroservices" instead. +238ms
rabbitmq      | 2021-08-26 12:36:23.084027+00:00 [info] <0.222.0> Feature flag `user_limits`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:23.084124+00:00 [info] <0.222.0> Feature flag `user_limits`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:23.085544+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.085637+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.085686+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.085753+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.085938+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.086036+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.086097+00:00 [info] <0.222.0> Feature flags:   [x] stream_queue
rabbitmq      | 2021-08-26 12:36:23.086146+00:00 [info] <0.222.0> Feature flags:   [~] user_limits
rabbitmq      | 2021-08-26 12:36:23.086202+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.086246+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:23 PM   ERROR [Server] Disconnected from RMQ. Trying to reconnect.
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:23 PM   ERROR [Server] Object:
hot-potato-player1 | {
hot-potato-player1 |   "err": {
hot-potato-player1 |     "cause": {
hot-potato-player1 |       "errno": -111,
hot-potato-player1 |       "code": "ECONNREFUSED",
hot-potato-player1 |       "syscall": "connect",
hot-potato-player1 |       "address": "172.23.0.3",
hot-potato-player1 |       "port": 5672
hot-potato-player1 |     },
hot-potato-player1 |     "isOperational": true,
hot-potato-player1 |     "errno": -111,
hot-potato-player1 |     "code": "ECONNREFUSED",
hot-potato-player1 |     "syscall": "connect",
hot-potato-player1 |     "address": "172.23.0.3",
hot-potato-player1 |     "port": 5672
hot-potato-player1 |   }
hot-potato-player1 | }
hot-potato-player1 |
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:23 PM   ERROR [Server] Disconnected from RMQ. Trying to reconnect.
rabbitmq      | 2021-08-26 12:36:23.118102+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:23.118257+00:00 [info] <0.222.0> Successfully synced tables from a peer
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:23 PM   ERROR [Server] Object:
hot-potato-player2 | {
hot-potato-player2 |   "err": {
hot-potato-player2 |     "cause": {
hot-potato-player2 |       "errno": -111,
hot-potato-player2 |       "code": "ECONNREFUSED",
hot-potato-player2 |       "syscall": "connect",
hot-potato-player2 |       "address": "172.23.0.3",
hot-potato-player2 |       "port": 5672
hot-potato-player2 |     },
hot-potato-player2 |     "isOperational": true,
hot-potato-player2 |     "errno": -111,
hot-potato-player2 |     "code": "ECONNREFUSED",
hot-potato-player2 |     "syscall": "connect",
hot-potato-player2 |     "address": "172.23.0.3",
hot-potato-player2 |     "port": 5672
hot-potato-player2 |   }
hot-potato-player2 | }
hot-potato-player2 |
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:23 PM   ERROR [Server] Disconnected from RMQ. Trying to reconnect.
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:23 PM   ERROR [Server] Object:
hot-potato-player3 | {
hot-potato-player3 |   "err": {
hot-potato-player3 |     "cause": {
hot-potato-player3 |       "errno": -111,
hot-potato-player3 |       "code": "ECONNREFUSED",
hot-potato-player3 |       "syscall": "connect",
hot-potato-player3 |       "address": "172.23.0.3",
hot-potato-player3 |       "port": 5672
hot-potato-player3 |     },
hot-potato-player3 |     "isOperational": true,
hot-potato-player3 |     "errno": -111,
hot-potato-player3 |     "code": "ECONNREFUSED",
hot-potato-player3 |     "syscall": "connect",
hot-potato-player3 |     "address": "172.23.0.3",
hot-potato-player3 |     "port": 5672
hot-potato-player3 |   }
hot-potato-player3 | }
hot-potato-player3 |
rabbitmq      | 2021-08-26 12:36:23.143227+00:00 [info] <0.222.0> Feature flag `user_limits`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:23.145701+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.145779+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.145936+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.145976+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.146013+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.146049+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.146160+00:00 [info] <0.222.0> Feature flags:   [x] stream_queue
rabbitmq      | 2021-08-26 12:36:23.146184+00:00 [info] <0.222.0> Feature flags:   [x] user_limits
rabbitmq      | 2021-08-26 12:36:23.146208+00:00 [info] <0.222.0> Feature flags:   [ ] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.146326+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:23.158512+00:00 [info] <0.222.0> Feature flag `virtual_host_metadata`: supported, attempt to enable...
rabbitmq      | 2021-08-26 12:36:23.158653+00:00 [info] <0.222.0> Feature flag `virtual_host_metadata`: mark as enabled=state_changing
rabbitmq      | 2021-08-26 12:36:23.159957+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.160016+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.160057+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.160096+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.160158+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.160182+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.160209+00:00 [info] <0.222.0> Feature flags:   [x] stream_queue
rabbitmq      | 2021-08-26 12:36:23.160274+00:00 [info] <0.222.0> Feature flags:   [x] user_limits
rabbitmq      | 2021-08-26 12:36:23.160948+00:00 [info] <0.222.0> Feature flags:   [~] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.161012+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:23.172375+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:23.172542+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:23.198303+00:00 [info] <0.222.0> Feature flag `virtual_host_metadata`: mark as enabled=true
rabbitmq      | 2021-08-26 12:36:23.202109+00:00 [info] <0.222.0> Feature flags: list of feature flags found:
rabbitmq      | 2021-08-26 12:36:23.202199+00:00 [info] <0.222.0> Feature flags:   [x] drop_unroutable_metric
rabbitmq      | 2021-08-26 12:36:23.202313+00:00 [info] <0.222.0> Feature flags:   [x] empty_basic_get_metric
rabbitmq      | 2021-08-26 12:36:23.202347+00:00 [info] <0.222.0> Feature flags:   [x] implicit_default_bindings
rabbitmq      | 2021-08-26 12:36:23.202384+00:00 [info] <0.222.0> Feature flags:   [x] maintenance_mode_status
rabbitmq      | 2021-08-26 12:36:23.202413+00:00 [info] <0.222.0> Feature flags:   [x] quorum_queue
rabbitmq      | 2021-08-26 12:36:23.202501+00:00 [info] <0.222.0> Feature flags:   [x] stream_queue
rabbitmq      | 2021-08-26 12:36:23.202532+00:00 [info] <0.222.0> Feature flags:   [x] user_limits
rabbitmq      | 2021-08-26 12:36:23.202567+00:00 [info] <0.222.0> Feature flags:   [x] virtual_host_metadata
rabbitmq      | 2021-08-26 12:36:23.202664+00:00 [info] <0.222.0> Feature flags: feature flag states written to disk: yes
rabbitmq      | 2021-08-26 12:36:23.215051+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:23.215371+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:23.234358+00:00 [info] <0.222.0> Waiting for Mnesia tables for 30000 ms, 9 retries left
rabbitmq      | 2021-08-26 12:36:23.234593+00:00 [info] <0.222.0> Successfully synced tables from a peer
rabbitmq      | 2021-08-26 12:36:23.234647+00:00 [info] <0.222.0> Peer discovery backend rabbit_peer_discovery_classic_config does not support registration, skipping registration.
rabbitmq      | 2021-08-26 12:36:23.234687+00:00 [info] <0.222.0> Will try to unlock with peer discovery backend rabbit_peer_discovery_classic_config
rabbitmq      | 2021-08-26 12:36:23.235001+00:00 [info] <0.222.0> Running boot step database_sync defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235227+00:00 [info] <0.222.0> Running boot step feature_flags defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235511+00:00 [info] <0.222.0> Running boot step codec_correctness_check defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235603+00:00 [info] <0.222.0> Running boot step external_infrastructure defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235635+00:00 [info] <0.222.0> Running boot step rabbit_registry defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235740+00:00 [info] <0.222.0> Running boot step rabbit_auth_mechanism_cr_demo defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.235957+00:00 [info] <0.222.0> Running boot step rabbit_queue_location_random defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.236031+00:00 [info] <0.222.0> Running boot step rabbit_event defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.236213+00:00 [info] <0.222.0> Running boot step rabbit_auth_mechanism_amqplain defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.236644+00:00 [info] <0.222.0> Running boot step rabbit_auth_mechanism_plain defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.237061+00:00 [info] <0.222.0> Running boot step rabbit_exchange_type_direct defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.237408+00:00 [info] <0.222.0> Running boot step rabbit_exchange_type_fanout defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.237662+00:00 [info] <0.222.0> Running boot step rabbit_exchange_type_headers defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.238106+00:00 [info] <0.222.0> Running boot step rabbit_exchange_type_topic defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.238565+00:00 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_all defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.238710+00:00 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_exactly defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.238789+00:00 [info] <0.222.0> Running boot step rabbit_mirror_queue_mode_nodes defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.239092+00:00 [info] <0.222.0> Running boot step rabbit_priority_queue defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.239166+00:00 [info] <0.222.0> Priority queues enabled, real BQ is rabbit_variable_queue
rabbitmq      | 2021-08-26 12:36:23.239468+00:00 [info] <0.222.0> Running boot step rabbit_queue_location_client_local defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.239853+00:00 [info] <0.222.0> Running boot step rabbit_queue_location_min_masters defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.240548+00:00 [info] <0.222.0> Running boot step kernel_ready defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.240958+00:00 [info] <0.222.0> Running boot step rabbit_sysmon_minder defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.241967+00:00 [info] <0.222.0> Running boot step rabbit_epmd_monitor defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.247139+00:00 [info] <0.562.0> epmd monitor knows us, inter-node communication (distribution) port: 25672
rabbitmq      | 2021-08-26 12:36:23.247362+00:00 [info] <0.222.0> Running boot step guid_generator defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.250747+00:00 [info] <0.222.0> Running boot step rabbit_node_monitor defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.251146+00:00 [info] <0.566.0> Starting rabbit_node_monitor
rabbitmq      | 2021-08-26 12:36:23.251687+00:00 [info] <0.222.0> Running boot step delegate_sup defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.253471+00:00 [info] <0.222.0> Running boot step rabbit_memory_monitor defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.254230+00:00 [info] <0.222.0> Running boot step core_initialized defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.254302+00:00 [info] <0.222.0> Running boot step upgrade_queues defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.261557+00:00 [info] <0.222.0> message_store upgrades: 1 to apply
rabbitmq      | 2021-08-26 12:36:23.261746+00:00 [info] <0.222.0> message_store upgrades: Applying rabbit_variable_queue:move_messages_to_vhost_store
rabbitmq      | 2021-08-26 12:36:23.261954+00:00 [info] <0.222.0> message_store upgrades: No durable queues found. Skipping message store migration
rabbitmq      | 2021-08-26 12:36:23.262327+00:00 [info] <0.222.0> message_store upgrades: Removing the old message store data
rabbitmq      | 2021-08-26 12:36:23.263515+00:00 [info] <0.222.0> message_store upgrades: All upgrades applied successfully
rabbitmq      | 2021-08-26 12:36:23.274112+00:00 [info] <0.222.0> Running boot step channel_tracking defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.278054+00:00 [info] <0.222.0> Setting up a table for channel tracking on this node: tracked_channel_on_node_rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:23.282969+00:00 [info] <0.222.0> Setting up a table for channel tracking on this node: tracked_channel_table_per_user_on_node_rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:23.283311+00:00 [info] <0.222.0> Running boot step rabbit_channel_tracking_handler defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.283393+00:00 [info] <0.222.0> Running boot step connection_tracking defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.288903+00:00 [info] <0.222.0> Setting up a table for connection tracking on this node: tracked_connection_on_node_rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:23.294313+00:00 [info] <0.222.0> Setting up a table for per-vhost connection counting on this node: tracked_connection_per_vhost_on_node_rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:23.299048+00:00 [info] <0.222.0> Setting up a table for per-user connection counting on this node: tracked_connection_table_per_user_on_node_rabbit@3389c4367da7
rabbitmq      | 2021-08-26 12:36:23.299551+00:00 [info] <0.222.0> Running boot step rabbit_connection_tracking_handler defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.299714+00:00 [info] <0.222.0> Running boot step rabbit_exchange_parameters defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.299896+00:00 [info] <0.222.0> Running boot step rabbit_mirror_queue_misc defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.300431+00:00 [info] <0.222.0> Running boot step rabbit_policies defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.301036+00:00 [info] <0.222.0> Running boot step rabbit_policy defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.301100+00:00 [info] <0.222.0> Running boot step rabbit_queue_location_validator defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.301161+00:00 [info] <0.222.0> Running boot step rabbit_quorum_memory_manager defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.301283+00:00 [info] <0.222.0> Running boot step rabbit_stream_coordinator defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.301869+00:00 [info] <0.222.0> Running boot step rabbit_vhost_limit defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.302028+00:00 [info] <0.222.0> Running boot step rabbit_mgmt_db_handler defined by app rabbitmq_management_agent
rabbitmq      | 2021-08-26 12:36:23.302130+00:00 [info] <0.222.0> Management plugin: using rates mode 'basic'
rabbitmq      | 2021-08-26 12:36:23.303273+00:00 [info] <0.222.0> Running boot step recovery defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.306646+00:00 [info] <0.222.0> Running boot step empty_db_check defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.306718+00:00 [info] <0.222.0> Will seed default virtual host and user...
rabbitmq      | 2021-08-26 12:36:23.306908+00:00 [info] <0.222.0> Adding vhost '/' (description: 'Default virtual host', tags: [])
rabbitmq      | 2021-08-26 12:36:23.336014+00:00 [info] <0.627.0> Making sure data directory '/var/lib/rabbitmq/mnesia/rabbit@3389c4367da7/msg_stores/vhosts/628WB79CIFDYO9LJI6DKMI09L' for vhost '/' exists
rabbitmq      | 2021-08-26 12:36:23.339283+00:00 [info] <0.627.0> Setting segment_entry_count for vhost '/' with 0 queues to '2048'
rabbitmq      | 2021-08-26 12:36:23.343622+00:00 [info] <0.627.0> Starting message stores for vhost '/'
rabbitmq      | 2021-08-26 12:36:23.343968+00:00 [info] <0.631.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_transient": using rabbit_msg_store_ets_index to provide index
rabbitmq      | 2021-08-26 12:36:23.346521+00:00 [info] <0.627.0> Started message store of type transient for vhost '/'
rabbitmq      | 2021-08-26 12:36:23.347029+00:00 [info] <0.635.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": using rabbit_msg_store_ets_index to provide index
rabbitmq      | 2021-08-26 12:36:23.348469+00:00 [warn] <0.635.0> Message store "628WB79CIFDYO9LJI6DKMI09L/msg_store_persistent": rebuilding indices from scratch
rabbitmq      | 2021-08-26 12:36:23.350207+00:00 [info] <0.627.0> Started message store of type persistent for vhost '/'
rabbitmq      | 2021-08-26 12:36:23.355170+00:00 [info] <0.222.0> Created user 'guest'
rabbitmq      | 2021-08-26 12:36:23.357435+00:00 [info] <0.222.0> Successfully set user tags for user 'guest' to [administrator]
rabbitmq      | 2021-08-26 12:36:23.359530+00:00 [info] <0.222.0> Successfully set permissions for 'guest' in virtual host '/' to '.*', '.*', '.*'
rabbitmq      | 2021-08-26 12:36:23.359612+00:00 [info] <0.222.0> Running boot step rabbit_looking_glass defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.359659+00:00 [info] <0.222.0> Running boot step rabbit_core_metrics_gc defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360107+00:00 [info] <0.222.0> Running boot step background_gc defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360444+00:00 [info] <0.222.0> Running boot step routing_ready defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360492+00:00 [info] <0.222.0> Running boot step pre_flight defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360576+00:00 [info] <0.222.0> Running boot step notify_cluster defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360638+00:00 [info] <0.222.0> Running boot step networking defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360707+00:00 [info] <0.222.0> Running boot step definition_import_worker_pool defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.360905+00:00 [info] <0.280.0> Starting worker pool 'definition_import_pool' with 6 processes in it
rabbitmq      | 2021-08-26 12:36:23.362121+00:00 [info] <0.222.0> Running boot step cluster_name defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.362322+00:00 [info] <0.222.0> Initialising internal cluster ID to 'rabbitmq-cluster-id-elpSqJ6Sm3YJoeT09iwn-w'
rabbitmq      | 2021-08-26 12:36:23.364899+00:00 [info] <0.222.0> Running boot step direct_client defined by app rabbit
rabbitmq      | 2021-08-26 12:36:23.365264+00:00 [info] <0.670.0> Resetting node maintenance status
rabbitmq      | 2021-08-26 12:36:23.413209+00:00 [info] <0.703.0> Prometheus metrics: HTTP (non-TLS) listener started on port 15692
rabbitmq      | 2021-08-26 12:36:23.413544+00:00 [info] <0.670.0> Ready to start client connection listeners
rabbitmq      | 2021-08-26 12:36:23.416742+00:00 [info] <0.747.0> started TCP listener on [::]:5672
rabbitmq      | 2021-08-26 12:36:23.603721+00:00 [info] <0.670.0> Server startup complete; 3 plugins started.
rabbitmq      | 2021-08-26 12:36:23.603721+00:00 [info] <0.670.0>  * rabbitmq_prometheus
rabbitmq      | 2021-08-26 12:36:23.603721+00:00 [info] <0.670.0>  * rabbitmq_web_dispatch
rabbitmq      | 2021-08-26 12:36:23.603721+00:00 [info] <0.670.0>  * rabbitmq_management_agent
rabbitmq      |  completed with 3 plugins.
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:23 PM     LOG [RoutesResolver] HealthController {/health}: +830ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:23 PM     LOG [RouterExplorer] Mapped {/health, GET} route +9ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:23 PM     LOG [RoutesResolver] PotatoController {/potato}: +1ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:23 PM     LOG [RouterExplorer] Mapped {/potato, GET} route +2ms
hot-potato-api | [Nest] 38  - 08/26/2021, 12:36:23 PM     LOG [NestApplication] Nest application successfully started +6ms
hot-potato-api | API server is running on http://0.0.0.0:3001
rabbitmq      | 2021-08-26 12:36:28.118431+00:00 [info] <0.752.0> accepting AMQP connection <0.752.0> (172.23.0.4:49536 -> 172.23.0.3:5672)
rabbitmq      | 2021-08-26 12:36:28.134349+00:00 [info] <0.755.0> accepting AMQP connection <0.755.0> (172.23.0.6:55884 -> 172.23.0.3:5672)
rabbitmq      | 2021-08-26 12:36:28.135400+00:00 [info] <0.761.0> accepting AMQP connection <0.761.0> (172.23.0.5:46272 -> 172.23.0.3:5672)
rabbitmq      | 2021-08-26 12:36:28.174468+00:00 [info] <0.752.0> connection <0.752.0> (172.23.0.4:49536 -> 172.23.0.3:5672): user 'guest' authenticated and granted access to vhost '/'
rabbitmq      | 2021-08-26 12:36:28.187549+00:00 [info] <0.761.0> connection <0.761.0> (172.23.0.5:46272 -> 172.23.0.3:5672): user 'guest' authenticated and granted access to vhost '/'
rabbitmq      | 2021-08-26 12:36:28.191543+00:00 [info] <0.755.0> connection <0.755.0> (172.23.0.6:55884 -> 172.23.0.3:5672): user 'guest' authenticated and granted access to vhost '/'
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:28 PM     LOG [NestMicroservice] Nest microservice successfully started +5108ms
hot-potato-player1 | Player is subscribed to amqp://rabbitmq:5672
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:28 PM     LOG [NestMicroservice] Nest microservice successfully started +5091ms
hot-potato-player3 | Player is subscribed to amqp://rabbitmq:5672
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:28 PM     LOG [NestMicroservice] Nest microservice successfully started +5100ms
hot-potato-player2 | Player is subscribed to amqp://rabbitmq:5672
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] HealthController {/health}: +18ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] HealthController {/health}: +17ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] HealthController {/health}: +17ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:28 PM     LOG [RouterExplorer] Mapped {/health, GET} route +7ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] PotatoController {/potato}: +1ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:28 PM     LOG [RouterExplorer] Mapped {/health, GET} route +7ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] PotatoController {/potato}: +1ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:28 PM     LOG [RouterExplorer] Mapped {/health, GET} route +6ms
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:28 PM     LOG [RoutesResolver] PotatoController {/potato}: +1ms
hot-potato-player1 | [Nest] 37  - 08/26/2021, 12:36:28 PM     LOG [NestApplication] Nest application successfully started +7ms
hot-potato-player3 | [Nest] 40  - 08/26/2021, 12:36:28 PM     LOG [NestApplication] Nest application successfully started +6ms
hot-potato-player1 | Player health check is running on http://0.0.0.0:4001/health
hot-potato-player2 | [Nest] 38  - 08/26/2021, 12:36:28 PM     LOG [NestApplication] Nest application successfully started +8ms
hot-potato-player3 | Player health check is running on http://0.0.0.0:4003/health
hot-potato-player2 | Player health check is running on http://0.0.0.0:4002/health

jwalton commented 3 years ago

@AminAlizadeh-m @sajjad-ser can you please give 3.5.0 a try? @EricWasTakenMJD found an obvious oversight in the connection code which might have been the cause of your problems.

TrejGun commented 3 years ago

I just said you can test there because it is fully configured minimal example, in case you don't want to dig nestjs' docs which are not the best

lundibundi commented 3 years ago

@jwalton FYI: I just tried 3.5.1 on another (not the repo above) nest.js project and it still (tried 3.4.0, 3.5.0) failed with

Error: Channel closed by server: 406 (PRECONDITION-FAILED) with message "PRECONDITION_FAILED - fast reply consumer does not exist"

Latest working version for me is 3.3.0 so I'd assume that the bug is somewhere in changes to 3.4.0.

jwalton commented 3 years ago

@lundibundi 3.4.0 is where I converted this whole repo to typescript, and I definitely made changes to how we connect because there were some cases that were probably not being handled correctly before. But... I don't understand how it could be causing this, or behaving any differently than it used to.

This was the code in 3.3.0: https://github.com/jwalton/node-amqp-connection-manager/blob/v3.3.0/src/AmqpConnectionManager.js#L140-L174

This is the same code in latest: https://github.com/jwalton/node-amqp-connection-manager/blob/master/src/AmqpConnectionManager.ts#L302-L345

Aside from this I changed some nulls to undefineds, and I made some minor changes to how we encode messages. None of this should be related (although, clearly, something is, because it works in 3.3.0 and doesn't in 3.4.0).

But, without more information, I'm not sure what I can do, other than just reverting all the changes and republishing 3.3.0. I've tried two different NestJS projects I found online and neither of them recreate this problem, and no one has shared a project or even posted their connection settings (except EricWasTakenMJD, who had a different problem).

@lundibundi @AminAlizadeh-m @sajjad-ser Can you please share the project you're seeing this in? If you can't, can you please copy/paste the options you're using to connect to RabbitMQ? Or add a console.log to AmqpConnectionManager._connect() and log what is being passed down to amqp.connect(connect, connectionOptions) using 3.3.0 vs latest?

luddd3 commented 3 years ago

Can it have something to do with https://github.com/jwalton/node-amqp-connection-manager/blob/eb14912c8b29844f10dc7f19c9995dd9becb4adb/src/ChannelWrapper.js#L239-L243

Before that change, all errors causing the channel to close were silently swallowed (which I think was wrong). I would want a precondition error to be emitted.

But that code was there in 3.3.0, so maybe it doesn't have anything to do with it.

jwalton commented 3 years ago

Not sure how this is related exactly, but this is related:

I just added this test case for "direct reply to", because it is definitely related. The test case, as written, is passing. But, if you don't bind a a consumer to the "amqp.rabbitmq.reply-to" channel, you get exactly this error. For example, if you change this bit:

        const rpcClient = connection.createChannel({
            setup: async (channel: ConfirmChannel) => {
                await channel.consume(
                    rpcClientQueueName,
                    (message) => {
                        result.resolve(message?.content.toString());
                    },
                    { noAck: true }
                );
            },
        });

To:

        const rpcClient = connection.createChannel();

Then you'll see this error happen every time. But, this is a legit error - you're sending messages with a replyTo for a queue that has no listeners bound to it.

NestJS is binding such a consumer here, and sending such requests here (unless you set the replyQueue option).

lundibundi commented 3 years ago

@jwalton thanks for quick investigation, I assumed that the repo posted before reproduced this so didn't add anything regarding configuration, my config is fairly basic: (where ClientsModule is a nest.js thing for connecting)

    ClientsModule.register([
      {
        name: 'SOME_SERVICE',
        transport: Transport.RMQ,
        options: {
          urls: [
            process.env.RABBITMQ_URL ||
              'amqp://rabbitmq:rabbitmq@rabbitmq:5672',
          ],
          queue: 'some_queue',
          queueOptions: {
            durable: true,
          },
        },
      },
    ]),

from the above IIUC the only thing passed from the app to the amqp is queueOptions: { durable: true }. So I don't think it will help much.

~~I'll try to start the app with 3.3.0 and 3.5.1 and add the info from AmqpConnectionManager._connect() in this comment a bit later .~~ Looks the issues is elsewhere:

v3.3.0
console.log(amqpUrl, connectionOptions);

amqp://rabbitmq:rabbitmq@localhost:5672?heartbeat=5 undefined
----

v3.5.1
console.log(connect, connectionOptions);

amqp://rabbitmq:rabbitmq@localhost:5672?heartbeat=5 undefined

I just added this test case for "direct reply to", because it is definitely related. The test case, as written, is passing. But, if you don't bind a a consumer to the "amqp.rabbitmq.reply-to" channel, you get exactly this error. For example, if you change this bit:

The error in usage of reply-to in nest.js was actually my first guess and I even started writing an issue there before finding this issue here and therefore postponing opening a bug there.

Another thing is that this fails anyway even when the consumer service is started beforehand (perhaps nest.js doesn't "register" it as a consumer).

But the question then is - why does this work in 3.3.0?

jwalton commented 3 years ago

But the question then is - why does this work in 3.3.0?

So weird. Other than reworking how I compute the connect URL, most of the other changes were in ChannelWrapper.

I moved some initialization out of the constructor and into the class itself (e.g. private _working = false; at the class level, instead of this._working = false in the constructor) which should be identical.
There were some default parameters I switched from null to undefined. e.g. addSetup(setup, done=null) is now addSetup(setup: SetupFunc, done?: Callback<void>).
this._settingUp, this._channel, this._irrecoverableCode are now undefined instead of null when we don't have values for them.
I made the bit that encodes messages into a buffer a bit more "explicit" - the typescript for amqplib only lets us pass in a Buffer, so I now convert strings to buffers instead of just passing the string to amqplib.
I converted a function full of "promise.then()`s into an async function.
One slightly interesting change I made is, on ChannelWrapper there are functions that just pass through to the underlying channel. For example:

    bindQueue() {
        return this._channel && this._channel.bindQueue.apply(this._channel, arguments);
    }

and I typescriptified these, so this is now:

    async bindQueue(queue: string, source: string, pattern: string, args?: any): Promise<void> {
        if (this._channel) {
            await this._channel.bindQueue(queue, source, pattern, args);
        }
    }

This is slightly different than the old version, because if you called the old version as bindQueue("foo"), we'd call this._channel.bindQueue("foo"), where now we'll call this._channel.bindQueue("foo", undefined, undefined, undefined). This is a subtle difference, but could be a source of defects if amqplib did tricks like checking arguments.length and doing different things based on that... but ampqlib doesn't appear to do such a thing.

In AmqpConnectionManager, the changes are even milder - this._currentConnection and this._connectPromise are undefined instead of null when they have no value, the aforementioned rework of figuring out what URL to connect to, and I added getters for the current channel count and the underlying connection.

None of this seems like it should affect anything. Although obviously something here does. :/

Oh... One important change I suppose I didn't consider - the old version of the code was hand written javascript, where the new version is compiled by the typescript compiler... This seems like an even less likely source of errors.

TrejGun commented 3 years ago

@jwalton hey hey

I was able to reproduce the bug using my repo, it was actually always there, you just did not get the point and did not call the URL to invoke the request. So here is an explanation:

NestJS uses two types of requests, emit - the one which sends the message and forgets about it, send - the one which waits for the response. The bug is only in the second one. That's why you were not able to reproduce the bug with https://github.com/rengthp/nestjs-rabbitmq-microservice/blob/master/microservice-client/src/app.controller.ts

pls ping me if you need more assistance

TrejGun commented 3 years ago

@jwalton can we give this a go?

jwalton commented 3 years ago

Hey Trej. I’ll have a look at this… soon. My mom passed away very unexpectedly and without any warning a week ago. I was supposed to be on vacation last week so I could take my daughter over to swim and play with her. Instead I’m planning a funeral. I’ll get back on this as soon as I can, but right now - as you can imagine - I… well… I have no words.

TrejGun commented 3 years ago

oh man, I'm so sorry

kevin192291 commented 3 years ago

@TrejGun Hey, Have you attempted to call:

async onApplicationBootstrap() {
    await this.<Your ClientProxy Instance>.connect();
  }

?

TrejGun commented 3 years ago

I believe this is covered by the framework, there is only

 app.connectMicroservice<MicroserviceOptions>({
    transport: Transport.RMQ,
    options: {
      urls: [process.env.RMQ_URL],
      queue: process.env.RMQ_QUEUE,
    },
  });

  await app
    .startAllMicroservices()

kevin192291 commented 3 years ago

I believe this is covered by the framework, there is only

 app.connectMicroservice<MicroserviceOptions>({
    transport: Transport.RMQ,
    options: {
      urls: [process.env.RMQ_URL],
      queue: process.env.RMQ_QUEUE,
    },
  });

  await app
    .startAllMicroservices()

It WAS, as of a recent release (i think v8) it is no longer connecting, and you must do it manually. It seems like regression to me, but I don't know if this was intended. That said, Try that out, at very least, try awaiting the connect right above your "SEND()" call. I suspect what you will see in your rabbitMQ management console is that BEFORE calling connect() you will NOT see a connection, then after, the connection will show up.

TrejGun commented 3 years ago

this happened after a major version update of nestjs . in fact, it has happened between 3.3.0 and 3.4.0 of this lib. anyways your suggestion does not work for me

@Module({
  controllers: [PotatoController],
  providers: [PotatoService],
  exports: [PotatoService],
})
export class PotatoModule {
  @Client({
    transport: Transport.RMQ,
    options: {
      urls: [process.env.RMQ_URL],
      queue: process.env.RMQ_QUEUE,
    },
  })
  client: ClientProxy;

  public async onApplicationBootstrap(): Promise<void> {
    console.log("!!!")
    await this.client.connect();
  }
}

you can check by yourself https://github.com/TrejGun/hot-potato-using-nestjs-microservices branch kevin192291

I thought the order of sending the messages and subscribing to the reply queue has changed but I was not able to find evidence while writing this answer

skliarovartem commented 2 years ago

I use your lib and also have "PRECONDITION_FAILED - fast reply consumer does not exist".

TrejGun commented 2 years ago

this error was fixed in latest nestjs

jwalton commented 2 years ago

Hey folks. I wanted to appologize - I kind of raised this issue and then abandoned it. My mom passed away very unexpectedly right after I raised this, and... well... It's been a rough couple of months. Thanks to everyone for helping get this fixed!

jwalton / node-amqp-connection-manager

New version has error in connection #172