search

ShellRechargeSolutionsEU / akka-rabbitmq

RabbitMq client in Scala and Akka actors
Other
229 stars 65 forks source link

A potential Bug #27

Closed wpc009 closed 8 years ago

wpc009 commented 8 years ago

When connection with rabbitmq server breaks. All ChannelActor drop old channel and require new channel from connectionActor. When connection recovered. The ConnectionActor send each children a new channel. And then it receive the new channel require sent by channelactors. This will cause duplicated channel created. And force close the previous channel which will cause unexpected ShutdownSignalException.

reinierl commented 8 years ago

Thanks for the report! We had some issues like that in the past and we thought we fixed them. I'm going to look into this.

reinierl commented 8 years ago

Can you elaborate a bit more on how this would be a problem?

Yes, it's possible that both the ConnectionActor and the ChannelActor start recovering. However, if the ChannelActor gets a second new channel from the ConnectionActor, this will be handled correctly as far as I can see. The ShutdownSignalException for the "first" new channel will be ignored because we check if this exception is about the current channel, and it is not.

Both the set-up of the new channel, and the shutdown signal are processed as Akka messages by the ChannelActor, so every ChannelMessage is processed on one of the two connections and the close never happens while a user operation with the channel is in progress.

wpc009 commented 8 years ago

When the ChannelActor receive a new Channel, it will close the old channel which will cause problem. Because the old channel is in use. There exists some reading or writing I/O operation which will be interrupted by the close of the old Channel.

Here is some logs:

2016-06-14 12:12:30.580  INFO --- [ main] com.m.sys.Bootstrap                         [                                                  ] : Starting Bootstrap on wpcs-MBP with PID 8810 (/Volumes/Data/wysa/idea_workspace/sys2/bootstrap/target/scala-2.11/classes started by wysa in /Volumes/Data/wysa/idea_workspace/sys2)
2016-06-14 12:12:30.584 DEBUG --- [ main] com.m.sys.Bootstrap                         [                                                  ] : Running with Spring Boot v1.3.3.RELEASE, Spring v4.2.5.RELEASE
2016-06-14 12:12:30.584  INFO --- [ main] com.m.sys.Bootstrap                         [                                                  ] : No active profile set, falling back to default profiles: default
2016-06-14 12:12:30.638  INFO --- [ main] o.s.c.a.AnnotationConfigApplicationContext         [                                                  ] : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@2fd6b6c7: startup date [Tue Jun 14 12:12:30 CST 2016]; root of context hierarchy
2016-06-14 12:12:33.182  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : Consul backend http://sysdev1.segmetics.com:8500
2016-06-14 12:12:33.419  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : get shared configs 1
2016-06-14 12:12:33.420  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : ignore empty cloudconfig/sys/wpcs-MBP/
2016-06-14 12:12:33.462  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : get shared configs 7
2016-06-14 12:12:33.463  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : ignore empty cloudconfig/sys/shared/
2016-06-14 12:12:33.463  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : ignore empty cloudconfig/sys/shared/op-rabbit/connection/
2016-06-14 12:12:33.463  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : ignore empty cloudconfig/sys/shared/op-rabbit/connection/hosts/
2016-06-14 12:12:33.490  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : op-rabbit.connection.hosts.0 -> Optional.of(sysdev2.segmetics.com),ci:623084, mi:623084, li:0
2016-06-14 12:12:33.491  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : op-rabbit.connection.password -> Optional.of(zapdos),ci:623079, mi:623079, li:0
2016-06-14 12:12:33.492  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : op-rabbit.connection.username -> Optional.of(zapdos),ci:623064, mi:623064, li:0
2016-06-14 12:12:33.492  INFO --- [ main] com.m.sys.bootstrap.CloudConfig             [                                                  ] : op-rabbit.connection.virtual-host -> Optional.of(/),ci:623052, mi:623065, li:0
2016-06-14 12:12:34.324  INFO --- [her-4] akka.event.slf4j.Slf4jLogger                       [                                                  ] : Slf4jLogger started
2016-06-14 12:12:34.472  INFO --- [her-4] akka.remote.Remoting                               [akka.remote.Remoting                              ] : Starting remoting
2016-06-14 12:12:34.782  INFO --- [her-2] akka.remote.Remoting                               [akka.remote.Remoting                              ] : Remoting started; listening on addresses :[akka.tcp://sys-test@127.0.0.1:2552]
2016-06-14 12:12:34.785  INFO --- [her-2] akka.remote.Remoting                               [akka.remote.Remoting                              ] : Remoting now listens on addresses: [akka.tcp://sys-test@127.0.0.1:2552]
2016-06-14 12:12:34.808  INFO --- [her-2] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Starting up...
2016-06-14 12:12:34.899  INFO --- [er-14] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Registered cluster JMX MBean [akka:type=Cluster]
2016-06-14 12:12:34.900  INFO --- [er-14] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Started up successfully
2016-06-14 12:12:34.911  INFO --- [er-14] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriate platform-specific native libary to 'java.library.path'. Reason: java.lang.ClassNotFoundException: org.hyperic.sigar.Sigar
2016-06-14 12:12:34.918  INFO --- [er-14] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Metrics collection has started successfully
2016-06-14 12:12:34.919  INFO --- [er-14] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - No seed-nodes configured, manual cluster join required
2016-06-14 12:12:35.136  INFO --- [ main] com.m.sys.Bootstrap                         [                                                  ] : Started Bootstrap in 5.105 seconds (JVM running for 6.997)
2016-06-14 12:12:35.153  INFO --- [her-4] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Node [akka.tcp://sys-test@127.0.0.1:2552] is JOINING, roles []
2016-06-14 12:12:35.180  INFO --- [her-4] akka.cluster.Cluster(akka://sys-test)              [akka.cluster.Cluster(akka://sys-test)             ] : Cluster Node [akka.tcp://sys-test@127.0.0.1:2552] - Leader is moving node [akka.tcp://sys-test@127.0.0.1:2552] to [Up]
2016-06-14 12:12:35.204  INFO --- [er-14] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : topic [/wpcs-MBP/service-manager] subscribe succeed
2016-06-14 12:12:35.206 DEBUG --- [er-14] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : Initialization -> Working
2016-06-14 12:12:35.207  INFO --- [er-14] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : service manager is ready.unstash all messages.
2016-06-14 12:12:35.222  INFO --- [er-15] com.m.sys.microservices.AMQPBridgeService   [//sys-test@127.0.0.1:2552/user/amqp-bridge-service] : amqp connecting to [sysdev2.segmetics.com]
2016-06-14 12:12:35.326 DEBUG --- [er-16] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Disconnected received CreateChannel(Props(Deploy(,Config(SimpleConfigObject({})),NoRouter,NoScopeGiven,,),class com.thenewmotion.akka.rabbitmq.ChannelActor,List(<function2>)),Some(publisher)): creating child Actor[akka://sys-test/user/rabbit-control/connection/publisher#1413130638] in disconnected state
2016-06-14 12:12:35.452  INFO --- [er-17] c.m.sys.java.microservices.DeviceManagerService    [akka.tcp://sys-test@127.0.0.1:2552/user/dm        ] : DeviceManager service pre-start
2016-06-14 12:12:35.462  WARN --- [er-17] c.m.sys.java.microservices.DeviceManagerService    [akka.tcp://sys-test@127.0.0.1:2552/user/dm        ] : unhandled message SubscribeAck(Subscribe(deviceManager,None,Actor[akka://sys-test/user/dm#44153486]))
2016-06-14 12:12:35.464  INFO --- [er-17] com.m.sys.java.microservices.ValveService   [akka.tcp://sys-test@127.0.0.1:2552/user/valve     ] : Valve service pre-start
2016-06-14 12:12:35.464  WARN --- [er-17] com.m.sys.java.microservices.ValveService   [akka.tcp://sys-test@127.0.0.1:2552/user/valve     ] : unhandled message SubscribeAck(Subscribe(valve,None,Actor[akka://sys-test/user/valve#575165068]))
2016-06-14 12:12:35.475  INFO --- [er-17] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : new local micro service [DeviceManager]:akka://sys-test/user/dm 
2016-06-14 12:12:35.492  INFO --- [er-17] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : new local micro service [Valve]:akka://sys-test/user/valve 
2016-06-14 12:12:35.678  INFO --- [her-2] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : micro-service DeviceManager-wpcs-MBP register succeed
2016-06-14 12:12:35.690  INFO --- [her-4] c.m.sys.java.microservices.DeviceManagerService    [akka.tcp://sys-test@127.0.0.1:2552/user/dm        ] : service DeviceManager-wpcs-MBP ready to go
2016-06-14 12:12:35.692  INFO --- [her-4] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : no one wants [DeviceManager] service, 
2016-06-14 12:12:35.706  INFO --- [er-17] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : micro-service Valve-wpcs-MBP register succeed
2016-06-14 12:12:35.707  INFO --- [er-17] com.m.sys.java.microservices.ValveService   [akka.tcp://sys-test@127.0.0.1:2552/user/valve     ] : service Valve-wpcs-MBP ready to go
2016-06-14 12:12:35.707  INFO --- [er-17] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : no one wants [Valve] service, 
2016-06-14 12:12:35.736 DEBUG --- [er-17] c.m.m.akka.server.ConnectorProtobufServer          [:2552/user/Connector-Manager/protobuf-server@34567] : bind /0.0.0.0:34567 success
2016-06-14 12:12:35.759  INFO --- [er-18] com.m.sys.bootstrap.HealthManager           [.tcp://sys-test@127.0.0.1:2552/user/health-manager] : [servicereg] micro service : DeviceManager-wpcs-MBP healthcheck registered.
2016-06-14 12:12:35.816  INFO --- [er-14] com.m.sys.bootstrap.HealthManager           [.tcp://sys-test@127.0.0.1:2552/user/health-manager] : [servicereg] micro service : Valve-wpcs-MBP healthcheck registered.
2016-06-14 12:12:36.021  INFO --- [er-15] com.datastax.driver.core.NettyUtil                 [                                                  ] : Did not find Netty's native epoll transport in the classpath, defaulting to NIO.
2016-06-14 12:12:36.154 DEBUG --- [her-4] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : setting up new connection amqp://zapdos@rabbitmq-server:5672/
2016-06-14 12:12:36.216 DEBUG --- [her-4] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:12:36.217  INFO --- [her-4] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher connected
2016-06-14 12:12:36.217  INFO --- [her-4] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection connected to amqp://zapdos@{sysdev2.segmetics.com:5672}:5672//
2016-06-14 12:12:36.258 DEBUG --- [her-4] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received CreateChannel(Props(Deploy(,Config(SimpleConfigObject({})),NoRouter,NoScopeGiven,,),class com.thenewmotion.akka.rabbitmq.ChannelActor,List(<function2>)),Some(confirmed-publisher-channel)): creating child Actor[akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel#1714535671] with channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:12:36.259 DEBUG --- [her-4] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:12:36.307  INFO --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel connected
2016-06-14 12:12:36.351 DEBUG --- [er-14] com.m.sys.microservices.AMQPBridgeService   [//sys-test@127.0.0.1:2552/user/amqp-bridge-service] : register to service-manager
2016-06-14 12:12:36.353  INFO --- [er-14] com.m.sys.microservices.AMQPBridgeService   [//sys-test@127.0.0.1:2552/user/amqp-bridge-service] : [amqp-bridge-service] starting
2016-06-14 12:12:36.355  INFO --- [er-18] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : new local micro service [amqp-bridge-service]:akka://sys-test/user/amqp-bridge-service 
2016-06-14 12:12:36.420  INFO --- [er-18] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : micro-service amqp-bridge-service-wpcs-MBP register succeed
2016-06-14 12:12:36.421  INFO --- [er-18] com.m.sys.microservices.AMQPBridgeService   [//sys-test@127.0.0.1:2552/user/amqp-bridge-service] : service amqp-bridge-service-wpcs-MBP ready to go
2016-06-14 12:12:36.421  INFO --- [er-17] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : no one wants [amqp-bridge-service] service, 
2016-06-14 12:12:36.690 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received CreateChannel(Props(Deploy(,Config(SimpleConfigObject({})),NoRouter,NoScopeGiven,,),class com.thenewmotion.akka.rabbitmq.ChannelActor,List(<function2>)),None): creating child Actor[akka://sys-test/user/rabbit-control/connection/$a#-1592843110] with channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:36.690 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:36.691 DEBUG --- [her-3] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Channel created; AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:36.691  INFO --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a connected
2016-06-14 12:12:36.697 DEBUG --- [er-14] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Setting up subscription to sys-test/amqp-bridge in akka://sys-test/user/rabbit-control/subscription-sys-test%2Famqp-bridge-1
2016-06-14 12:12:37.069  INFO --- [er-15] c.d.driver.core.policies.DCAwareRoundRobinPolicy   [                                                  ] : Using data-center name 'datacenter1' for DCAwareRoundRobinPolicy (if this is incorrect, please provide the correct datacenter name with DCAwareRoundRobinPolicy constructor)
2016-06-14 12:12:37.071  INFO --- [er-15] com.datastax.driver.core.Cluster                   [                                                  ] : New Cassandra host sysdev2.segmetics.com/rabbitmq-server:9042 added
2016-06-14 12:12:37.071  INFO --- [er-15] com.datastax.driver.core.Cluster                   [                                                  ] : New Cassandra host sysdev1.segmetics.com/123.56.206.96:9042 added
2016-06-14 12:12:37.113  INFO --- [her-4] c.m.sys.java.microservices.DataHouseService [akka.tcp://sys-test@127.0.0.1:2552/user/dh        ] : DataHouse service pre-start
2016-06-14 12:12:37.113  WARN --- [her-4] c.m.sys.java.microservices.DataHouseService [akka.tcp://sys-test@127.0.0.1:2552/user/dh        ] : unhandled message SubscribeAck(Subscribe(dataHouse,None,Actor[akka://sys-test/user/dh#-1200968676]))
2016-06-14 12:12:37.114  INFO --- [her-4] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : new local micro service [DataHouse]:akka://sys-test/user/dh 
2016-06-14 12:12:37.178  INFO --- [her-4] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : micro-service DataHouse-wpcs-MBP register succeed
2016-06-14 12:12:37.178  INFO --- [her-4] c.m.sys.java.microservices.DataHouseService [akka.tcp://sys-test@127.0.0.1:2552/user/dh        ] : service DataHouse-wpcs-MBP ready to go
2016-06-14 12:12:37.179  INFO --- [her-4] com.m.sys.bootstrap.ServiceManager          [tcp://sys-test@127.0.0.1:2552/user/service-manager] : no one wants [DataHouse] service, 
2016-06-14 12:12:37.468  INFO --- [her-3] com.m.sys.microservices.AMQPBridgeService   [//sys-test@127.0.0.1:2552/user/amqp-bridge-service] : [amqp-bridge-service] ready
2016-06-14 12:12:37.662  INFO --- [her-3] com.m.sys.bootstrap.HealthManager           [.tcp://sys-test@127.0.0.1:2552/user/health-manager] : [servicereg] micro service : amqp-bridge-service-wpcs-MBP healthcheck registered.
2016-06-14 12:12:37.723  INFO --- [her-4] com.m.sys.bootstrap.HealthManager           [.tcp://sys-test@127.0.0.1:2552/user/health-manager] : [servicereg] micro service : DataHouse-wpcs-MBP healthcheck registered.
2016-06-14 12:12:56.942 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:12:56.953 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:12:56.958 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:12:56.996 ERROR --- [er-21] com.spingo.op_rabbit.ConfirmedPublisherActor       [0.0.1:2552/user/rabbit-control/confirmed-publisher] : Publisher channel was disconnected unexpectedly

com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
    at com.rabbitmq.client.impl.AMQConnection.startShutdown(AMQConnection.java:739)
    at com.rabbitmq.client.impl.AMQConnection.shutdown(AMQConnection.java:729)
    at com.rabbitmq.client.impl.AMQConnection.handleConnectionClose(AMQConnection.java:668)
    at com.rabbitmq.client.impl.AMQConnection.psysessControlCommand(AMQConnection.java:622)
    at com.rabbitmq.client.impl.AMQConnection$1.psysessAsync(AMQConnection.java:103)
    at com.rabbitmq.client.impl.AMQChannel.handleCompleteInboundCommand(AMQChannel.java:144)
    at com.rabbitmq.client.impl.AMQChannel.handleFrame(AMQChannel.java:91)
    at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:546)
    at java.lang.Thread.run(Thread.java:745)

2016-06-14 12:12:56.997 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:12:56.997 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received AmqpShutdownSignal(com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)): shutdown (initiated by app false)
2016-06-14 12:12:56.997 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection closing broken connection amqp://zapdos@rabbitmq-server:5672/
2016-06-14 12:12:56.999 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:12:56.999 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:12:56.999 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:56.999 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:12:56.999  WARN --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection lost connection to amqp://zapdos@{sysdev2.segmetics.com:5672}:5672//
2016-06-14 12:12:57.000 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:12:57.000 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:12:57.002 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher asking for new channel
2016-06-14 12:12:57.002  WARN --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher disconnected
2016-06-14 12:12:57.002 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel asking for new channel
2016-06-14 12:12:57.002  WARN --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel disconnected
2016-06-14 12:12:57.003 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a asking for new channel
2016-06-14 12:12:57.003  WARN --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a disconnected
2016-06-14 12:12:57.146 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : setting up new connection amqp://zapdos@rabbitmq-server:5672/
2016-06-14 12:12:57.186 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:12:57.186 DEBUG --- [er-17] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Channel created; AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:12:57.187  INFO --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a connected
2016-06-14 12:12:57.187 DEBUG --- [er-17] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Setting up subscription to sys-test/amqp-bridge in akka://sys-test/user/rabbit-control/subscription-sys-test%2Famqp-bridge-1
2016-06-14 12:12:57.233 DEBUG --- [er-17] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:12:57.271  INFO --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel connected
2016-06-14 12:12:57.272  INFO --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection connected to amqp://zapdos@{sysdev2.segmetics.com:5672}:5672//
2016-06-14 12:12:57.275 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:57.277  INFO --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher connected
2016-06-14 12:12:57.319 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:12:57.319 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:12:57.359 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:12:57.362 DEBUG --- [er-21] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,5): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:12:57.365 DEBUG --- [er-18] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:12:57.366 DEBUG --- [er-18] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4)
2016-06-14 12:12:57.401 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:12:57.402 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:12:57.402 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:12:57.403 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,5)
2016-06-14 12:12:57.440 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:12:57.442 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6)
2016-06-14 12:12:57.442 DEBUG --- [her-2] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Channel created; AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6)
2016-06-14 12:12:57.442 DEBUG --- [her-2] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Setting up subscription to sys-test/amqp-bridge in akka://sys-test/user/rabbit-control/subscription-sys-test%2Famqp-bridge-1
2016-06-14 12:13:17.375 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:13:17.378 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:13:17.383 ERROR --- [her-2] com.spingo.op_rabbit.ConfirmedPublisherActor       [0.0.1:2552/user/rabbit-control/confirmed-publisher] : Publisher channel was disconnected unexpectedly

com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
    at com.rabbitmq.client.impl.AMQConnection.startShutdown(AMQConnection.java:739)
    at com.rabbitmq.client.impl.AMQConnection.shutdown(AMQConnection.java:729)
    at com.rabbitmq.client.impl.AMQConnection.handleConnectionClose(AMQConnection.java:668)
    at com.rabbitmq.client.impl.AMQConnection.psysessControlCommand(AMQConnection.java:622)
    at com.rabbitmq.client.impl.AMQConnection$1.psysessAsync(AMQConnection.java:103)
    at com.rabbitmq.client.impl.AMQChannel.handleCompleteInboundCommand(AMQChannel.java:144)
    at com.rabbitmq.client.impl.AMQChannel.handleFrame(AMQChannel.java:91)
    at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:546)
    at java.lang.Thread.run(Thread.java:745)

2016-06-14 12:13:17.394 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:13:17.415 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)
2016-06-14 12:13:17.415 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received AmqpShutdownSignal(com.rabbitmq.client.ShutdownSignalException: connection error; protocol method: #method<connection.close>(reply-code=320, reply-text=CONNECTION_FORCED - Closed via management plugin, class-id=0, method-id=0)): shutdown (initiated by app false)
2016-06-14 12:13:17.416 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection closing broken connection amqp://zapdos@rabbitmq-server:5672/
2016-06-14 12:13:17.416  WARN --- [her-2] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection lost connection to amqp://zapdos@{sysdev2.segmetics.com:5672}:5672//
2016-06-14 12:13:17.416 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:13:17.416 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6)
2016-06-14 12:13:17.416 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a asking for new channel
2016-06-14 12:13:17.416  WARN --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a disconnected
2016-06-14 12:13:17.417 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:13:17.417 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,5)
2016-06-14 12:13:17.417 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel asking for new channel
2016-06-14 12:13:17.417 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : in Connected received ParentShutdownSignal: shutdown
2016-06-14 12:13:17.417 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher closing broken channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4)
2016-06-14 12:13:17.417  WARN --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel disconnected
2016-06-14 12:13:17.418 DEBUG --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher asking for new channel
2016-06-14 12:13:17.418  WARN --- [her-2] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher disconnected
2016-06-14 12:13:17.620 DEBUG --- [er-18] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : setting up new connection amqp://zapdos@rabbitmq-server:5672/
2016-06-14 12:13:17.662 DEBUG --- [er-16] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:13:17.663 DEBUG --- [er-16] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Channel created; AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:13:17.663  INFO --- [er-16] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a connected
2016-06-14 12:13:17.663 DEBUG --- [er-16] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Setting up subscription to sys-test/amqp-bridge in akka://sys-test/user/rabbit-control/subscription-sys-test%2Famqp-bridge-1
2016-06-14 12:13:17.699 DEBUG --- [er-18] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:13:17.738  INFO --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel connected
2016-06-14 12:13:17.738 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:13:17.738  INFO --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher connected
2016-06-14 12:13:17.738  INFO --- [er-14] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection connected to amqp://zapdos@{sysdev2.segmetics.com:5672}:5672//
2016-06-14 12:13:17.775 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:13:17.776 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,1)
2016-06-14 12:13:17.778 ERROR --- [er-14] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : An error while trying to bind a consumer to sys-test/amqp-bridge

java.io.IOException: null
    at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:106)
    at com.rabbitmq.client.impl.AMQChannel.wrap(AMQChannel.java:102)
    at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:124)
    at com.rabbitmq.client.impl.ChannelN.queueBind(ChannelN.java:945)
    at com.rabbitmq.client.impl.ChannelN.queueBind(ChannelN.java:959)
    at com.rabbitmq.client.impl.ChannelN.queueBind(ChannelN.java:61)
    at com.spingo.op_rabbit.Binding$$anon$2$$anonfun$declare$2.apply(Binding.scala:71)
    at com.spingo.op_rabbit.Binding$$anon$2$$anonfun$declare$2.apply(Binding.scala:71)
    at scala.collection.immutable.List.foreach(List.scala:381)
    at com.spingo.op_rabbit.Binding$$anon$2.declare(Binding.scala:71)
    at com.spingo.op_rabbit.SubscriptionActor.doSubscribe(SubscriptionActor.scala:232)
    at com.spingo.op_rabbit.SubscriptionActor$$anonfun$8.applyOrElse(SubscriptionActor.scala:159)
    at com.spingo.op_rabbit.SubscriptionActor$$anonfun$8.applyOrElse(SubscriptionActor.scala:146)
    at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:36)
    at akka.actor.FSM$$anonfun$handleTransition$1.apply(FSM.scala:597)
    at akka.actor.FSM$$anonfun$handleTransition$1.apply(FSM.scala:597)
    at scala.collection.immutable.List.foreach(List.scala:381)
    at akka.actor.FSM$class.handleTransition(FSM.scala:597)
    at akka.actor.FSM$class.makeTransition(FSM.scala:679)
    at com.spingo.op_rabbit.SubscriptionActor.makeTransition(SubscriptionActor.scala:13)
    at akka.actor.FSM$class.applyState(FSM.scala:664)
    at com.spingo.op_rabbit.SubscriptionActor.applyState(SubscriptionActor.scala:13)
    at akka.actor.FSM$class.psysessEvent(FSM.scala:659)
    at com.spingo.op_rabbit.SubscriptionActor.akka$actor$LoggingFSM$$super$psysessEvent(SubscriptionActor.scala:13)
    at akka.actor.LoggingFSM$class.psysessEvent(FSM.scala:790)
    at com.spingo.op_rabbit.SubscriptionActor.psysessEvent(SubscriptionActor.scala:13)
    at akka.actor.FSM$class.akka$actor$FSM$$psysessMsg(FSM.scala:648)
    at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:642)
    at akka.actor.Actor$class.aroundReceive(Actor.scala:480)
    at com.spingo.op_rabbit.SubscriptionActor.aroundReceive(SubscriptionActor.scala:13)
    at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)
    at akka.actor.ActorCell.invoke(ActorCell.scala:495)
    at akka.dispatch.Mailbox.psysessMailbox(Mailbox.scala:257)
    at akka.dispatch.Mailbox.run(Mailbox.scala:224)
    at akka.dispatch.Mailbox.exec(Mailbox.scala:234)
    at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
    at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
    at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
    at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
Caused by: com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
    at com.rabbitmq.utility.ValueOrException.getValue(ValueOrException.java:67)
    at com.rabbitmq.utility.BlockingValueOrException.uninterruptibleGetValue(BlockingValueOrException.java:33)
    at com.rabbitmq.client.impl.AMQChannel$BlockingRpcContinuation.getReply(AMQChannel.java:361)
    at com.rabbitmq.client.impl.AMQChannel.privateRpc(AMQChannel.java:226)
    at com.rabbitmq.client.impl.AMQChannel.exnWrappingRpc(AMQChannel.java:118)
    ... 36 common frames omitted
Caused by: com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
    at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:554)
    at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:509)
    at com.rabbitmq.client.impl.ChannelN.close(ChannelN.java:503)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.thenewmotion.akka.rabbitmq.RabbitMqActor$class.closeIfOpen(RabbitMqActor.scala:27)
    at com.thenewmotion.akka.rabbitmq.ChannelActor.closeIfOpen(ChannelActor.scala:34)
    at com.thenewmotion.akka.rabbitmq.ChannelActor$$anonfun$2.applyOrElse(ChannelActor.scala:115)
    at com.thenewmotion.akka.rabbitmq.ChannelActor$$anonfun$2.applyOrElse(ChannelActor.scala:112)
    at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:36)
    at akka.actor.FSM$class.psysessEvent(FSM.scala:654)
    at com.thenewmotion.akka.rabbitmq.ChannelActor.psysessEvent(ChannelActor.scala:34)
    at akka.actor.FSM$class.akka$actor$FSM$$psysessMsg(FSM.scala:648)
    at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:642)
    at akka.actor.Actor$class.aroundReceive(Actor.scala:480)
    at com.thenewmotion.akka.rabbitmq.ChannelActor.aroundReceive(ChannelActor.scala:34)
    ... 9 common frames omitted

2016-06-14 12:13:17.812 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:13:17.813 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,5): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,2)
2016-06-14 12:13:17.813 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:13:17.813 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4)
2016-06-14 12:13:17.813 DEBUG --- [er-14] com.spingo.op_rabbit.SubscriptionActor             [bbit-control/subscription-sys-test%2Famqp-bridge-1] : Channel created; AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4)
2016-06-14 12:13:17.814  INFO --- [er-14] .r.RemoteActorRefProvider$RemoteDeadLetterActorRef [akka://sys-test/deadLetters                       ] : Message [com.spingo.op_rabbit.SubscriptionActor$ChannelConnected] from Actor[akka://sys-test/deadLetters] to Actor[akka://sys-test/deadLetters] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
2016-06-14 12:13:17.814 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : akka://sys-test/user/rabbit-control/connection/$a closing channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,4)
2016-06-14 12:13:17.852 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ConnectionActor     [test@127.0.0.1:2552/user/rabbit-control/connection] : akka://sys-test/user/rabbit-control/connection in Connected received ProvideChannel: channel acquired
2016-06-14 12:13:17.853 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : in Connected received AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6): closing unexpected channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,3)
2016-06-14 12:13:17.853 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:13:17.853 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [bit-control/connection/confirmed-publisher-channel] : akka://sys-test/user/rabbit-control/connection/confirmed-publisher-channel setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,5)
2016-06-14 12:13:17.853 DEBUG --- [her-3] com.thenewmotion.akka.rabbitmq.ChannelActor        [t@127.0.0.1:2552/user/rabbit-control/connection/$a] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:13:17.854  INFO --- [her-3] akka.actor.LocalActorRef                           [akka://sys-test/user/rabbit-control/connection/$a ] : Message [com.thenewmotion.akka.rabbitmq.AmqpShutdownSignal] from Actor[akka://sys-test/user/rabbit-control/connection/$a#-1592843110] to Actor[akka://sys-test/user/rabbit-control/connection/$a#-1592843110] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
2016-06-14 12:13:17.854  INFO --- [her-3] akka.actor.LocalActorRef                           [akka://sys-test/user/rabbit-control/connection/$a ] : Message [com.thenewmotion.akka.rabbitmq.AmqpShutdownSignal] from Actor[akka://sys-test/user/rabbit-control/connection/$a#-1592843110] to Actor[akka://sys-test/user/rabbit-control/connection/$a#-1592843110] was not delivered. [3] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
2016-06-14 12:13:17.893 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : on shutdownCompleted com.rabbitmq.client.ShutdownSignalException: clean channel shutdown; protocol method: #method<channel.close>(reply-code=200, reply-text=OK, class-id=0, method-id=0)
2016-06-14 12:13:17.893 DEBUG --- [er-14] com.thenewmotion.akka.rabbitmq.ChannelActor        [.0.1:2552/user/rabbit-control/connection/publisher] : akka://sys-test/user/rabbit-control/connection/publisher setting up new channel AMQChannel(amqp://zapdos@rabbitmq-server:5672/,6)

Version: 2.3. Steps to Reproduce:

  1. After consumer ready. Close the connection between rabbitmq-server and the client from the rabbitmq's administration web page.
  2. Retry several times, the above exception will appear.

The cause is Caused by: com.rabbitmq.client.ShutdownSignalException, it show that this line at com.spingo.op_rabbit.SubscriptionActor.doSubscribe(SubscriptionActor.scala:232) was broken by the close of the old channel.

wpc009 commented 8 years ago

I will make a Pull request for this.

DieMyst commented 8 years ago

I have same problem, as in this issue. How can I avoid it now?

reinierl commented 8 years ago

You should not let the reference to the channel escape from the closures passed to the ChannelActor with ChannelMessage. Then you should be fine.

reinierl commented 8 years ago

It also turns out that op-rabbit was letting the channel reference escape this way (see https://github.com/SpinGo/op-rabbit/issues/72). Closing this issue because it was not a malfunction of akka-rabbitmq.