[AMQ-7081] After AMQ-7079 abortSlowAckConsumerStrategy aborts connection by default

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Not A Bug
• Component/s: Broker
• Assignee: Gary Tully
• Reporter: Simon Lundstrom
• Created: 19/Oct/18 08:51
• Updated: 19/Oct/18 13:55
• Resolved: 19/Oct/18 13:54

Description

The fix of AMQ-7079 introduced a breaking change bug since the default value of maxSlowCount=-1 was longer enough for abortSlowAckConsumerStrategy to just configure the slow consumer detection but it started to disconnect the consumer as well.{{}}

Setting maxSlowDuration="-1" doesn't disconnect the consumer though but I don't think we should change the old default behavior.

Pre AMQ-7079 fix:

<abortSlowAckConsumerStrategy checkPeriod="1000" maxTimeSinceLastAck="3000" maxSlowCount="-1" />

worked before in just detecting a slow consumer. consumer was not disconnected.

After AMQ-7079 fix:

<abortSlowAckConsumerStrategy checkPeriod="1000" maxTimeSinceLastAck="3000" maxSlowCount="-1" />

disconnects the consumer; ActiveMQ logs:

2018-10-19 10:42:33,124 | INFO  | aborting slow consumer: ID:kaka.it.su.se-53364-1539938520009-1:1:1:1 for destination:queue://su.it.linfra.simlu | org.apache.activemq.broker.region.policy.AbortSlowConsumerStrategy | ActiveMQ Broker[localhost] Scheduler
2018-10-19 10:42:50,250 | WARN  | no matching consumer, ignoring ack null | org.apache.activemq.broker.TransportConnection | ActiveMQ Transport: tcp:///127.0.0.1:53365@61616
2018-10-19 10:42:50,257 | WARN  | Async error occurred: java.lang.IllegalStateException: Cannot remove a consumer that had not been registered: ID:kaka.it.su.se-53364-1539938520009-1:1:1:1 | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport: tcp:///127.0.0.1:53365@61616

Spring Boot logs:

2018-10-19 10:42:00.209  INFO 65846 --- [           main] se.su.it.simlu.esb.App                   : Started App in 1.849 seconds (JVM running for 2.386)
2018-10-19 10:42:33.129  WARN 65846 --- [0.1:61616@53365] org.apache.activemq.ActiveMQSession      : Closed consumer on Command, ID:kaka.it.su.se-53364-1539938520009-1:1:1:1
2018-10-19 10:42:50.247  INFO 65846 --- [enerContainer-1] se.su.it.simlu.esb.Consumer              : Message Received: Enter some text here for the message body...
2018-10-19 10:42:50.261  WARN 65846 --- [enerContainer-1] o.s.j.l.DefaultMessageListenerContainer  : Setup of JMS message listener invoker failed for destination 'su.it.linfra.simlu' - trying to recover. Cause: The Consumer is closed
2018-10-19 10:42:50.300  INFO 65846 --- [enerContainer-1] o.s.j.l.DefaultMessageListenerContainer  : Successfully refreshed JMS Connection

 
The order ("Consumer closed" before "Message Received") is weird because I just use a simple Thread.sleep I suspect:

  @Transactional
  @JmsListener(destination = "su.it.linfra.simlu")
  public void receiveQueue(String text) throws Exception {
    Thread.sleep(50000);
    log.info("Message Received: "+text);
  }