Occasional issue with links running, but upstreams missing.

[jemc]

We have a three-site federation production RabbitMQ system, with each site containing a three-node cluster of RabbitMQ servers. We have certain federated exchanges linking the three sites to eachother in a fully-connected-graph topology. There are more than one federated exchanges in the graph (for different types of messages).

Twice in production federation systems so far (within a month or so of operation), we have seen cases where federation fails "silently" in the following way:

• In the management interface of the "downstream" site nodes, all federation links are shown to be running.
• In the federation status eval report of the "downstream" site nodes, all federation links are shown to be running.
• In the management interface of the "upstream" site nodes, in the "exchanges" page, we see the internal federation: exchanges, but one of the exchanges that funnel to one of several sites is simply missing from the list, though all others appear as normal.
• In the management interface of the "upstream" site nodes, in the "queues" page, we see the internal federation: queues, but one of the exchanges that funnel to one of several sites is simply missing from the list, though all others appear as normal.

I call this failing "silently" because the errant link reports as running, even though it will not carry any messages because the upstream exchange and queue are missing. I've confirmed that this is not just a reporting issue - messages that are supposed to be federated across that link do not reach the downstream, nor are they queued upstream because there is no queue - they are effectively discarded.

Both times it has happened, restarting nodes in the "downstream" cluster did not help. I resolved this issue by performing a rolling restart of the "upstream" cluster, though the second time I noticed that I only had to restart one of the three nodes.

After the first time, we have added to our watchdog service a check that ensures this correct number of upstream federation: exchanges and queues exist for each node, as well as checking on the federation link count and status. However, we consider this to be a hack rather than a viable long term solution, as the check only informs us that messages are already being discarded, which shouldn't happen when our federation configuration is steady-state (we are not adding or removing upstreams during normal operation).

[jemc]

RabbitMQ server version is 3.5.3.

I'm pasting an excerpt of the logs from the "upstream" node that I restarted this most recent time. The vhosts, hosts, usernames, and passwords have been anonymized (consistently). In the anonymized naming scheme, the hostname of the node generating these logs would be called node-1.site-a. The downstream site that failed and caused this issue on recovery was site-c.

Note that there is one federation exchange running that links node-1.site-a to itself, and when this closes on shutdown you see an error message, but that is to be expected and not related to this ticket. I don't immediately see any error messages that are particularly relevant to the issue of this ticket (the inconsistency that remains after the links are supposedly healed).

Here is an excerpt starting during the last part of the network issues that separated the working site site-a from its failing (unreachable) downstream site site-c, including when the failing site started being reachable again (around 20:31:17 in the logs), up to the point when I restarted the rabbitmq-server.

192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:30:35 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'foreign' in vhost 'foo' on amqp://node-3.site-c/foo
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:35 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'global' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 {error,econnrefused}
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:35 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'foreign' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 {error,econnrefused}
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:36 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'global' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 {error,econnrefused}
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:36 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'foreign' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 {error,econnrefused}
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:30:38 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'foreign' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:30:38 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'global' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:41 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'global' in vhost 'foo' on amqp://node-3.site-c/foo
192.168.3.21 {error,etimedout}
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:30:43 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'global' in vhost 'foo' on amqp://node-3.site-c/foo
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:30:53 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'foreign' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 {error,etimedout}
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:31:02 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' did not connect to exchange 'global' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 {error,etimedout}
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:17 ===
192.168.3.21 accepting AMQP connection <0.12295.114> (node-2.site-c:35265 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:18 ===
192.168.3.21 accepting AMQP connection <0.12316.114> (node-2.site-c:36687 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:18 ===
192.168.3.21 closing AMQP connection <0.12316.114> (node-2.site-c:36687 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:19 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'global' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:24 ===
192.168.3.21 accepting AMQP connection <0.12387.114> (node-2.site-c:57660 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:25 ===
192.168.3.21 accepting AMQP connection <0.12407.114> (node-2.site-c:54820 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:25 ===
192.168.3.21 closing AMQP connection <0.12407.114> (node-2.site-c:54820 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:31:26 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' connected to exchange 'foreign' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:36:33 ===
192.168.3.21 closing AMQP connection <0.8468.114> (192.168.3.73:34704 -> 192.168.3.21:5672):
192.168.3.21 connection_closed_abruptly
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::20:59:03 ===
192.168.3.21 closing AMQP connection <0.8278.114> (192.168.3.31:56470 -> 192.168.3.21:5672):
192.168.3.21 connection_closed_abruptly
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::20:59:42 ===
192.168.3.21 accepting AMQP connection <0.13110.114> (192.168.3.30:46568 -> 192.168.3.21:5672)
192.168.3.21 

Here is the excerpt starting immediately after the above log entries, when I stopped this RabbitMQ node:

192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Stopping RabbitMQ
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Stopping RabbitMQ
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 stopped TCP Listener on [::]:5672
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8336.114> (192.168.3.31:56512 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8042.114> (192.168.3.30:55693 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8595.114> (192.168.3.73:34777 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8401.114> (192.168.3.52:54609 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8927.114> (192.168.3.30:56217 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8976.114> (192.168.3.30:56283 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:50 ===
192.168.3.21 Error on AMQP connection <0.8417.114> (192.168.3.73:34675 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8465.114> (192.168.3.73:34701 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8952.114> (192.168.3.31:57037 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.13110.114> (192.168.3.30:46568 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8520.114> (192.168.3.73:34730 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8147.114> (192.168.3.30:55842 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8137.114> (192.168.3.30:55809 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8304.114> (192.168.3.31:56491 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8583.114> (192.168.3.31:56668 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8152.114> (192.168.3.30:55850 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8197.114> (192.168.3.30:55902 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8964.114> (192.168.3.30:56281 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8718.114> (192.168.3.52:54743 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8126.114> (192.168.3.30:55800 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8825.114> (192.168.3.52:54841 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8351.114> (192.168.3.31:56533 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8486.114> (192.168.3.31:56632 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8694.114> (192.168.3.52:54723 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8757.114> (192.168.3.52:54806 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8167.114> (192.168.3.30:55885 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.12295.114> (node-2.site-c:35265 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8940.114> (192.168.3.30:56260 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8509.114> (192.168.3.31:56640 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8316.114> (192.168.3.73:34618 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8030.114> (192.168.3.30:55676 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8114.114> (192.168.3.30:55790 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8380.114> (192.168.3.31:56554 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8483.114> (192.168.3.31:56628 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8547.114> (192.168.3.31:56653 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8843.114> (192.168.3.52:54845 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8634.114> (192.168.3.31:56697 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8682.114> (192.168.3.52:54711 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.9016.114> (192.168.3.52:55185 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8078.114> (192.168.3.30:55741 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8267.114> (192.168.3.73:34574 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8598.114> (192.168.3.31:56687 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8729.114> (192.168.3.52:54751 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8054.114> (192.168.3.30:55717 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.2314.0> (node-1.site-a:59140 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8234.114> (192.168.3.73:34550 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8442.114> (192.168.3.73:34683 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8178.114> (192.168.3.30:55894 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.22116.111> (192.168.3.30:39444 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8083.114> (192.168.3.30:55745 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8592.114> (192.168.3.52:54633 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8807.114> (192.168.3.52:54837 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8392.114> (192.168.3.31:56563 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8408.114> (192.168.3.31:56573 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8559.114> (192.168.3.31:56659 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8655.114> (192.168.3.52:54644 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8742.114> (192.168.3.52:54759 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8529.114> (192.168.3.31:56642 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8327.114> (192.168.3.73:34629 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8705.114> (192.168.3.52:54734 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8670.114> (192.168.3.52:54665 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8988.114> (192.168.3.30:56286 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8246.114> (192.168.3.73:34564 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8066.114> (192.168.3.30:55722 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.18051.9> (node-1.site-b:44261 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8293.114> (192.168.3.31:56481 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8607.114> (192.168.3.73:34779 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8787.114> (192.168.3.52:54825 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8836.114> (192.168.3.52:54843 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8754.114> (192.168.3.52:54804 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8802.114> (192.168.3.52:54833 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.12387.114> (node-2.site-c:57660 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8258.114> (192.168.3.73:34572 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8210.114> (192.168.3.30:55917 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8768.114> (192.168.3.52:54812 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8096.114> (192.168.3.30:55751 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.18048.9> (node-1.site-b:58529 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8405.114> (192.168.3.31:56572 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Error on AMQP connection <0.8556.114> (192.168.3.73:34753 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser', state: running), channel 0:
192.168.3.21 {amqp_error,connection_forced,
192.168.3.21             "broker forced connection closure with reason 'shutdown'",none}
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Connection (<0.2307.0>) closing: received hard error {'connection.close',320,
192.168.3.21                                                       <<"CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'">>,
192.168.3.21                                                       0,0} from server
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 ** Generic server <0.2307.0> terminating 
192.168.3.21 ** Last message in was socket_closed
192.168.3.21 ** When Server state == {state,amqp_network_connection,
192.168.3.21                             {state,#Port<0.8725>,
192.168.3.21                                 <<"client 192.168.3.21:59140 -> node-1.site-a:5672">>,
192.168.3.21                                 580,<0.2310.0>,131072,<0.2306.0>,
192.168.3.21                                 {server_initiated_close,320,
192.168.3.21                                     <<"CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'">>},
192.168.3.21                                 false},
192.168.3.21                             <0.2309.0>,
192.168.3.21                             {amqp_params_network,<<"foouser">>,
192.168.3.21                                 <<"foouserpassword">>,<<"foo">>,"node-1.site-a",
192.168.3.21                                 5672,0,0,0,infinity,none,
192.168.3.21                                 [#Fun<amqp_uri.9.9354953>,
192.168.3.21                                  #Fun<amqp_uri.9.9354953>],
192.168.3.21                                 [],[]},
192.168.3.21                             0,
192.168.3.21                             [{<<"capabilities">>,table,
192.168.3.21                               [{<<"publisher_confirms">>,bool,true},
192.168.3.21                                {<<"exchange_exchange_bindings">>,bool,true},
192.168.3.21                                {<<"basic.nack">>,bool,true},
192.168.3.21                                {<<"consumer_cancel_notify">>,bool,true},
192.168.3.21                                {<<"connection.blocked">>,bool,true},
192.168.3.21                                {<<"consumer_priorities">>,bool,true},
192.168.3.21                                {<<"authentication_failure_close">>,bool,true},
192.168.3.21                                {<<"per_consumer_qos">>,bool,true}]},
192.168.3.21                              {<<"cluster_name">>,longstr,
192.168.3.21                               <<"rabbit@baz-site1-prod-rabbitmq-192-168-3-21">>},
192.168.3.21                              {<<"copyright">>,longstr,
192.168.3.21                               <<"Copyright (C) 2007-2014 GoPivotal, Inc.">>},
192.168.3.21                              {<<"information">>,longstr,
192.168.3.21                               <<"Licensed under the MPL.  See http://www.rabbitmq.com/">>},
192.168.3.21                              {<<"platform">>,longstr,<<"Erlang/OTP">>},
192.168.3.21                              {<<"product">>,longstr,<<"RabbitMQ">>},
192.168.3.21                              {<<"version">>,longstr,<<"3.5.3">>}],
192.168.3.21                             none,
192.168.3.21                             {closing,server_initiated_close,
192.168.3.21                                 {'connection.close',320,
192.168.3.21                                     <<"CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'">>,
192.168.3.21                                     0,0},
192.168.3.21                                 none}}
192.168.3.21 ** Reason for termination == 
192.168.3.21 ** socket_closed_unexpectedly
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnected from exchange 'global' in vhost 'foo' on amqp://node-1.site-a/foo
192.168.3.21 {upstream_channel_down,
192.168.3.21     {connection_closing,
192.168.3.21         {server_initiated_close,320,
192.168.3.21             <<"CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'">>}}}
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-3.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-3.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-2.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-1.site-c/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-3.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-3.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-2.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-2.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'foreign' in vhost 'foo' on amqp://node-1.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:03:51 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-1.site-b/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:01 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-3.site-a/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:11 ===
192.168.3.21 Federation exchange 'local' in vhost 'foo' disconnecting from exchange 'global' in vhost 'foo' on amqp://node-2.site-a/foo
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:11 ===
192.168.3.21 Stopped RabbitMQ application
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:11 ===
192.168.3.21 Halting Erlang VM

And here is the portion of the log immediately after the above portion, when I started the RabbitMQ server again:

192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:14 ===
192.168.3.21 Starting RabbitMQ 3.5.3 on Erlang R14B04
192.168.3.21 Copyright (C) 2007-2014 GoPivotal, Inc.
192.168.3.21 Licensed under the MPL.  See http://www.rabbitmq.com/
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:14 ===
192.168.3.21 node           : rabbit@baz-site1-prod-rabbitmq-192-168-3-21
192.168.3.21 home dir       : /var/lib/rabbitmq
192.168.3.21 config file(s) : /etc/rabbitmq/rabbitmq.config
192.168.3.21 cookie hash    : xUq8HX/AMFFjCC9fddG/Qw==
192.168.3.21 log            : /var/log/rabbitmq/rabbit@baz-site1-prod-rabbitmq-192-168-3-21.log
192.168.3.21 sasl log       : /var/log/rabbitmq/rabbit@baz-site1-prod-rabbitmq-192-168-3-21-sasl.log
192.168.3.21 database dir   : /var/lib/rabbitmq/mnesia/rabbit@baz-site1-prod-rabbitmq-192-168-3-21
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Memory limit set to 3194MB of 7986MB total.
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Disk free limit set to 50MB
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Limiting to approx 63900 file handles (57508 sockets)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Priority queues enabled, real BQ is rabbit_variable_queue
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Management plugin: using rates mode 'basic'
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 msg_store_transient: using rabbit_msg_store_ets_index to provide index
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 msg_store_persistent: using rabbit_msg_store_ets_index to provide index
192.168.3.21 
192.168.3.21 =WARNING REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 msg_store_persistent: recovery terms differ from present
192.168.3.21 rebuilding indices from scratch
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Mirrored queue 'foo.some_queue_1' in vhost 'foo': Adding mirror on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-21': <0.363.0>
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Mirrored queue 'foo.some_queue_2' in vhost 'foo': Adding mirror on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-21': <0.367.0>
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Mirrored queue 'dead.foo' in vhost 'foo': Adding mirror on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-21': <0.371.0>
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Mirrored queue 'foo.some_queue_3' in vhost 'foo': Adding mirror on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-21': <0.375.0>
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 started TCP Listener on [::]:5672
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 rabbit on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-23' up
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Management plugin started. Port: 15672
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 rabbit on node 'rabbit@baz-site1-prod-rabbitmq-192-168-3-24' up
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Server startup complete; 9 plugins started.
192.168.3.21  * rabbitmq_management_visualiser
192.168.3.21  * rabbitmq_federation_management
192.168.3.21  * rabbitmq_management
192.168.3.21  * rabbitmq_federation
192.168.3.21  * rabbitmq_management_agent
192.168.3.21  * rabbitmq_web_dispatch
192.168.3.21  * webmachine
192.168.3.21  * mochiweb
192.168.3.21  * amqp_client
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.434.0> (node-1.site-b:58696 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.438.0> (node-1.site-b:45723 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.459.0> (node-2.site-a:45544 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.479.0> (node-2.site-a:52723 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 closing AMQP connection <0.479.0> (node-2.site-a:52723 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Channel error on connection <0.459.0> (node-2.site-a:45544 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser'), channel 1:
192.168.3.21 {amqp_error,not_found,
192.168.3.21             "no exchange 'federation: global -> rabbit@baz-site1-prod-rabbitmq-192-168-3-21:local B' in vhost 'foo'",
192.168.3.21             'exchange.bind'}
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 closing AMQP connection <0.459.0> (node-2.site-a:45544 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.508.0> (node-2.site-c:52527 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 accepting AMQP connection <0.511.0> (node-2.site-c:47495 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.566.0> (node-2.site-c:39869 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.569.0> (node-2.site-c:52573 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.588.0> (node-1.site-b:36586 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.591.0> (node-1.site-b:59920 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 closing AMQP connection <0.566.0> (node-2.site-c:39869 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 closing AMQP connection <0.569.0> (node-2.site-c:52573 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 closing AMQP connection <0.588.0> (node-1.site-b:36586 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 closing AMQP connection <0.591.0> (node-1.site-b:59920 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.643.0> (node-2.site-a:48185 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 accepting AMQP connection <0.667.0> (node-2.site-a:39473 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:16 ===
192.168.3.21 closing AMQP connection <0.667.0> (node-2.site-a:39473 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:22 ===
192.168.3.21 accepting AMQP connection <0.727.0> (192.168.3.31:49498 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:35 ===
192.168.3.21 accepting AMQP connection <0.744.0> (192.168.3.31:49557 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:38 ===
192.168.3.21 accepting AMQP connection <0.763.0> (192.168.3.30:48233 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:38 ===
192.168.3.21 accepting AMQP connection <0.775.0> (192.168.3.31:49567 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:45 ===
192.168.3.21 accepting AMQP connection <0.789.0> (192.168.3.30:48264 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:45 ===
192.168.3.21 accepting AMQP connection <0.801.0> (192.168.3.52:47192 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:49 ===
192.168.3.21 accepting AMQP connection <0.814.0> (192.168.3.31:49616 -> 192.168.3.21:5672)
192.168.3.21 
192.168.3.21 =INFO REPORT==== 20-Jul-2015::21:04:51 ===
192.168.3.21 accepting AMQP connection <0.826.0> (192.168.3.52:47213 -> 192.168.3.21:5672)
192.168.3.21 

[michaelklishin]

Thanks. The most likely reason is that the exchange isn't guaranteed to be declared on recovery, e.g. due to a race condition or an edge case. I can't think of anything else at the moment.

[jemc]

@michaelklishin - I'm assuming that you mean the downstream exchange (local) may not immediately be available then the downstream site nodes are recovering from site failure. I just looked at the logs for the downstream site, and they don't show a shut down or start up sequence during the period when the downstream site came back online, so it looks like those nodes believed that they just continued to be online from their perspective. If that's true, I'm not sure why the local exchange wouldn't exist in the downstream at the moment when the federation link is recovered.

[jemc]

@michaelklishin - When this happens again, is there any additional information I can gather while the server is in the errant state that would assist you in debugging?

[michaelklishin]

@jemc rabbitmqctl report (feel free to obfuscate queue names as long as binding and consumer info is updated accordingly)

[michaelklishin]

So

192.168.3.21 =ERROR REPORT==== 20-Jul-2015::21:04:15 ===
192.168.3.21 Channel error on connection <0.459.0> (node-2.site-a:45544 -> 192.168.3.21:5672, vhost: 'foo', user: 'foouser'), channel 1:
192.168.3.21 {amqp_error,not_found,
192.168.3.21             "no exchange 'federation: global -> rabbit@baz-site1-prod-rabbitmq-192-168-3-21:local B' in vhost 'foo'",
192.168.3.21             'exchange.bind'}

seems to be the culprit here. We've seen a similarly looking report elsewhere.

[michaelklishin]

@jemc any chance there could have been a policy change that affected exchange federation around the time?

[jemc]

No, I don't think so. The first case happened shortly after we initially set up the infrastructure, so it's possible in that case, but in the second case it was definitely in steady state - I don't think there were any policy changes that could have been made, and I'm the only one who was really dealing with the infrastructure at that point.

[jemc]

This just happened again after a rolling upgrade from 3.5.3 to 3.5.6. I've sent a tar.gz with rabbitmqctl report dumps and more information to mklishin AT pivotal DOT io.

[jemc]

I forgot to mention here that I ended up stabilizing the problem that day by:

• removing all federation upstream configuration from each cluster
• adding all federation upstream again to each cluster

However, today it happened again after a temporary cloud partial-outage in one cluster. I was forced to do the same process again. This is while still running 3.5.6.

[jemc]

This has since happened two more times since the last comment (13 days ago). Any update on this?

[michaelklishin]

@jemc no updates. We are on the finish line with the 3.6.0 release at the moment.

[icyice80]

HI

I am experiencing an similar problem. The federated exchange created on the upstream gets removed when i stop/start the rabbitmq service on the downstream cluster, This operation is performed sequentially on the each node within the downstream cluster. and it only happens when the stats db gets to change from one node to another. I have posted an question on the googe-group (rabbitmq-user). here is the link https://groups.google.com/forum/#!topic/rabbitmq-users/mzg9NQZUAEU. Its seems to do with auto-delete set to true?

the all rabbitmq instances are running 3.3.4 on the windows boxes.

Cheers

[michaelklishin]

The issue seems to be with an auto-deleted exchange. Someone is investigating why they are used so frequently (seemingly by default).

[jemc]

I'm not sure I understand - I don't know if the upstream exchanges/queues created by the federation plugin are auto_delete or not, but I am certain the exchanges that we configure explicitly to be federated are created with auto_delete: false - it's part of our chef script.

[icyice80]

@jemc, how did you set auto-delete to false?

[jemc]

@icyice80 The exchanges are created via the PUT /api/exchanges/vhost/exchange_name endpoint of the HTTP API, "auto_delete": false part of the JSON payload. This happens every time we use Chef to provision a new RabbitMQ node.

[icyice80]

@jemc, I meant the federation exchange, starts with federation:(MessageName), once you add your federation policy in the downstream, the federation exchange and its queue will get automatically created on the upstream.

[jemc]

Ah, regarding those, as I said two comments above:

I don't know if the upstream exchanges/queues created by the federation plugin are auto_delete or not

[icyice80]

@jemc you could check that under details section for the federation exchange via the management interface

[jemc]

@icyice80 Looks like auto-delete: true for the federation exchanges.

[Gsantomaggio]

Hi @jemc , @icyice80

We found two potential issues related to direct-connections ( used by federation plug-in ) and auto-delete flag. We are working on it, and if it possible we need:

1. rabbitmqctl report output
2. know which client(s) are you using (.NET,Java,.....)

Upload the reports to the group thread or, if you prefer, send to my email. Feel free to obfuscate sensitive data Thank you

[icyice80]

HI @Gsantomaggio

I am using .net client library via masstransit service bus. In regards to the report output, do you need it from all the nodes or the upstreams or downstreams?

Cheers

[Gsantomaggio]

HI @icyice80

It'd useful to have down-stream and upstream reports

Thanks

[jemc]

@Gsantomaggio - do you want rabbitmqctl report output for the system when it's in the correct state or when it's in the erroneous state? Upon looking at it more, I think the output I sent to @michaelklishin from the erroneous state is not fully correct (that is, not fully erroneous), so I hesitate to send it if it might mislead you. If you need output from the correct state, I can gather and send it now. If you need output from the erroneous state, we'll have to wait for our system to malfunction again and try to quickly gather the output before repairing and resuming data flow.

The client I'm using for produce/consume operations is the rabbitmq-c client, wrapped in Ruby with a library that I wrote - ruby-rabbitmq. However, all of the federation configuration and exchanges are set up via the RabbitMQ HTTP API, as I described in above comments.

[Gsantomaggio]

Hi @jemc It'd useful in erroneous state. Thank you

[Gsantomaggio]

Hi @icyice80 and @jemc

We modified the heartbeat default value: https://github.com/rabbitmq/rabbitmq-erlang-client/issues/25. Please read here https://www.rabbitmq.com/heartbeats.html for more details
heartbeat can help to solve this issue. When the upstream connection is recreated the link applies the federation policy, this will recreate the missing exchanges .

Meanwhile you could try to modify your upstream configuration, in this way: amqp://user:user@yourserver?heartbeat=10

10 is the new default value, but feel free to test with different values. Let me know!

Thanks

[jemc]

@Gsantomaggio - It sounds like you're talking about the federation link connections, not our "normal" application connections for consumers/producers, right?

If so, what do we have to do to upgrade so that the federation plugin uses the latest erlang client version?

[Gsantomaggio]

@jemc Yes, I'm talking about federation connections. Federation connections use rabbitmq-erlang-client

In order to use the new rabbitmq-erlang-client configuration you have two ways: 1 - Wait the version 3.5.7, will be released soon ( suggested ) 2 - Use this amqp://user:user@yourserver?heartbeat=10 configuration

In general using heartbeat is a good practise, as you can see here and here, heartbeat will be enabled by default

[michaelklishin]

@jemc wait for 3.5.7, which will be out next week. It will include rabbitmq/rabbitmq-erlang-client#25. In the meantime, you can configure your links to use a heartbeat (say, 10 seconds) via URI parameters. Again, this is more a workaround than a real solution but can relieve you from some ops pain in the short term.

[jemc]

Thanks, @michaelklishin and @Gsantomaggio, for getting to the root of the problem - I'm glad it was a simple fix once found.

We'll wait for the upgrade. Thanks!

[icyice80]

@Gsantomaggio, @michaelklishin I have changed the federation upstreams to have the heartbeat value as suggested in the uri parameter. It does not seem that the missing federation exchange(s) get recreated. @Gsantomaggio I have sent you the report when they are in erroneous state. currently we are on rabbitmq version 3.3.4. Thanks.

[jemc]

A bump on this.

We upgraded to 3.5.7 in production and this issue is not yet solved by the heartbeat fix in the erlang client. It's still outstanding...

[michaelklishin]

At this point I don't believe that this is a single issue. We've recently discovered what the real issue was in https://github.com/rabbitmq/rabbitmq-federation/issues/7, for example. There can be more. I'm leaving this open for the time being but we are out of ideas on this specific log file.

[tuukkala]

I am having a similar issue with federated exchanges quietly not working. I have been testing failover cases and if I create a network split to my cluster it causes a similar quiet federation failure.

The problem occurs when I create a short network split on the downstream cluster. After autoheal finishes the federation link seems to break. The admin ui shows that all links are running but from the upstream side I can see that the exchange for the particular federation is missing the binding from the local exchange to the federation exchange (the from -> this exchange part is missing). The link starts working if I recreate the federation upstream policy in the downstream cluster. I am testing with 2 server clusters on both sides. The policy recreation is enough I do not need to reboot any of the servers.

[tuukkala]

Any update on this issue? I made a separate post to the mailin list about the issue https://groups.google.com/forum/#!topic/rabbitmq-users/70p-7Udujzo

[michaelklishin]

As of 3.6.11 we believe this was addressed. @tuukkala had a setup that reproduced the issue easily and no longer does.

[ghost]

I believe I am seeing a similar issue with version 3.5.7. I've setup the federation upstreams on my exchanges, setup their policies, and saw that the link running in 'Federation Status' for the exchanges I've setup to be federated. After a day or so without touching or changing anything it seems that the Federation Status goes away. The log I get is similar to what @jemc originally posted:

=INFO REPORT==== 1-Mar-2018::14:35:21 === Federation exchange 'events' in vhost 'dev_foo' disconnecting from exchange 'events' in vhost '/dev_main' on amqp://ipaddressremoved/%2Fdev_main

@michaelklishin do you have any ideas on this, or should 3.6.11 fix this?

Thanks!

[michaelklishin]

The milestone on this issue as well as a comment above say that we believe it was addressed in 3.6.11. 3.5.x has been out of support for a while and is not getting any more releases. Consider upgrading, 3.5.7 is close to 20 releases behind.

[naveene84]

Hi Michael,

We have two rabbitmq clusters with 3 nodes in each cluster. Few of the queue/exchange federation links are missing, every time we restart rabbitmq nodes as part of maintenance.

rabbitmqctl --version 3.7.12 Please help us to overcome this issue and let me know if you need more info regarding this issue.

Thanks, Naveen

[lukebakken]

@naveene84 - rabbitmq/discussions#16