Consumer is busy for the lack of credits. Current credits = -2147104758 Can't receive reference

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Consumer is busy for the lack of credits. Current credits = -2147104758 Can't receive reference

Pachod, Joseph (GE Healthcare)
Hello

I've seen multiple lines like this one on the broker:
2020-01-23 16:37:34,697 DEBUG ServerConsumerImpl - ServerConsumerImpl [id=0, filter=null, binding=LocalQueueBinding [address=jms.queue.SNIP, queue=QueueImpl[name=jms.queue.SNIP, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=30d35e98-11b6-11ea-b356-005056010e08]]@701fc37a, filter=null, name=jms.queue.SNIP, clusterName=jms.queue.SNIP30d35e98-11b6-11ea-b356-005056010e08]] is busy for the lack of credits. Current credits = -2147104758 Can't receive reference Reference[2263750177]:RELIABLE:ServerMessage[messageID=2263750177,durable=true,userID=46c0c8b1-3df6-11ea-81bf-005056010e08,priority=4, bodySize=8327, timestamp=Thu Jan 23 16:37:34 CET 2020,expiration=0, durable=true, address=jms.queue.SNIP,properties=TypedProperties[__AMQ_CID=a3059b6c-394d-11ea-81bf-005056010e08,_AMQ_DUPL_ID=MESSAGE_TYPE_RAW|C_STORE|1.2.40.0.13.1.328212600455283165464857800437653470543|1.3.12.2.1107.5.1.4.95769.30000020012306121223600024591|202001231637]]@1304899032

After a few lines like this, then there is:
[server=ActiveMQServerImpl::serverUUID=30d35e98-11b6-11ea-b356-005056010e08]]@701fc37a::All the consumers were busy, giving up now

On the consumer side, there are plenty of "normal" lines like:
2020-01-23 16:40:00,619 DEBUG ClientConsumerImpl:821 - Sending 437355 from flow-control
2020-01-23 16:40:00,775 DEBUG ClientConsumerImpl:821 - Sending 274818 from flow-control

And then plenty of lines like:
2020-01-23 16:41:42,712 DEBUG recovery:72 - looking for recover at ClientSessionImpl [name=7f9ded8c-394e-11ea-b19b-005056010e08, username=null, closed=false, factory = org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@148ec922, metaData=()]@42f5051f configuration [XARecoveryConfig [transportConfiguration=[TransportConfiguration(name=, factory=org-apache-activemq-artemis-core-remoting-impl-netty-NettyConnectorFactory) ?port=61616&localAddress=0-0-0-0&host=127-0-0-1], discoveryConfiguration=null, username=null, password=****, JNDI_NAME=java:jboss/DefaultJMSConnectionFactory]]
And then plenty like this:
2020-01-23 17:09:44,113 DEBUG ClientSessionImpl:867 - Calling close on session ClientSessionImpl [name=e6200652-3dd8-11ea-b19b-005056010e08, username=null, closed=false, factory = org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@1b51cc95, metaData=(jms-session=,)]@68839616
And then plenty like this:
2020-01-23 17:09:44,117 DEBUG ClientSessionImpl:862 - Session was already closed, giving up now, this=ClientSessionImpl [name=e6200652-3dd8-11ea-b19b-005056010e08, username=null, closed=true, factory = org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@1b51cc95, metaData=(jms-session=,)]@68839616

This happened after running fine for a few weeks.

I don't understand why there would be credit issue on the customer side: no messages are waiting for processing.

Does it look like a normal behavior?

Furthermore the log "Current credits = -2147104758" is also troubling: it's Integer.MIN_VALUE in fact. Could there be an integer overflow issue?

The doc says in https://activemq.apache.org/components/artemis/documentation/latest/flow-control.html :
"By default, the consumerWindowSize is set to 1 MiB (1024 * 1024 bytes) unless overridden via (Address Settings)

The value can be:

-1 for an unbounded buffer

0 to not buffer any messages.

>0 for a buffer with the given maximum size in bytes."

Regarding the log we've, i hesitate between -1 or 0. Any preference? Any better way?

FYI, we currently use the default configuration, knowing that the consumer is in Wildfly and the broker in a Spring Boot app. And artemis version is 1.5.5 on both sides, really old i know, sorry for this.

Thanks in advance

Kind regards
Joseph PACHOD
Staff Software Architect
GE Healthcare

Reply | Threaded
Open this post in threaded view
|

Re: Consumer is busy for the lack of credits. Current credits = -2147104758 Can't receive reference

jbertram
The DEBUG logs are typically used by developers who are familiar with the
code-base. The logs can certainly give the wrong impression if you don't
know the context of the information they provide. Unless you're actually
seeing a problem in your application(s) then I suggest you ignore the DEBUG
logging. If you are seeing an actual problem please elaborate on what it is
from a functional perspective rather than citing DEBUG logs.


Justin

On Fri, Jan 31, 2020 at 2:41 AM Pachod, Joseph (GE Healthcare) <
[hidden email]> wrote:

> Hello
>
> I've seen multiple lines like this one on the broker:
> 2020-01-23 16:37:34,697 DEBUG ServerConsumerImpl - ServerConsumerImpl
> [id=0, filter=null, binding=LocalQueueBinding [address=jms.queue.SNIP,
> queue=QueueImpl[name=jms.queue.SNIP, postOffice=PostOfficeImpl
> [server=ActiveMQServerImpl::serverUUID=30d35e98-11b6-11ea-b356-005056010e08]]@701fc37a,
> filter=null, name=jms.queue.SNIP,
> clusterName=jms.queue.SNIP30d35e98-11b6-11ea-b356-005056010e08]] is busy
> for the lack of credits. Current credits = -2147104758 Can't receive
> reference
> Reference[2263750177]:RELIABLE:ServerMessage[messageID=2263750177,durable=true,userID=46c0c8b1-3df6-11ea-81bf-005056010e08,priority=4,
> bodySize=8327, timestamp=Thu Jan 23 16:37:34 CET 2020,expiration=0,
> durable=true,
> address=jms.queue.SNIP,properties=TypedProperties[__AMQ_CID=a3059b6c-394d-11ea-81bf-005056010e08,_AMQ_DUPL_ID=MESSAGE_TYPE_RAW|C_STORE|1.2.40.0.13.1.328212600455283165464857800437653470543|1.3.12.2.1107.5.1.4.95769.30000020012306121223600024591|202001231637]]@1304899032
>
> After a few lines like this, then there is:
> [server=ActiveMQServerImpl::serverUUID=30d35e98-11b6-11ea-b356-005056010e08]]@701fc37a::All
> the consumers were busy, giving up now
>
> On the consumer side, there are plenty of "normal" lines like:
> 2020-01-23 16:40:00,619 DEBUG ClientConsumerImpl:821 - Sending 437355 from
> flow-control
> 2020-01-23 16:40:00,775 DEBUG ClientConsumerImpl:821 - Sending 274818 from
> flow-control
>
> And then plenty of lines like:
> 2020-01-23 16:41:42,712 DEBUG recovery:72 - looking for recover at
> ClientSessionImpl [name=7f9ded8c-394e-11ea-b19b-005056010e08,
> username=null, closed=false, factory =
> org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@148ec922,
> metaData=()]@42f5051f configuration [XARecoveryConfig
> [transportConfiguration=[TransportConfiguration(name=,
> factory=org-apache-activemq-artemis-core-remoting-impl-netty-NettyConnectorFactory)
> ?port=61616&localAddress=0-0-0-0&host=127-0-0-1],
> discoveryConfiguration=null, username=null, password=****,
> JNDI_NAME=java:jboss/DefaultJMSConnectionFactory]]
> And then plenty like this:
> 2020-01-23 17:09:44,113 DEBUG ClientSessionImpl:867 - Calling close on
> session ClientSessionImpl [name=e6200652-3dd8-11ea-b19b-005056010e08,
> username=null, closed=false, factory =
> org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@1b51cc95,
> metaData=(jms-session=,)]@68839616
> And then plenty like this:
> 2020-01-23 17:09:44,117 DEBUG ClientSessionImpl:862 - Session was already
> closed, giving up now, this=ClientSessionImpl
> [name=e6200652-3dd8-11ea-b19b-005056010e08, username=null, closed=true,
> factory =
> org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@1b51cc95,
> metaData=(jms-session=,)]@68839616
>
> This happened after running fine for a few weeks.
>
> I don't understand why there would be credit issue on the customer side:
> no messages are waiting for processing.
>
> Does it look like a normal behavior?
>
> Furthermore the log "Current credits = -2147104758" is also troubling:
> it's Integer.MIN_VALUE in fact. Could there be an integer overflow issue?
>
> The doc says in
> https://activemq.apache.org/components/artemis/documentation/latest/flow-control.html
> :
> "By default, the consumerWindowSize is set to 1 MiB (1024 * 1024 bytes)
> unless overridden via (Address Settings)
>
> The value can be:
>
> -1 for an unbounded buffer
>
> 0 to not buffer any messages.
>
> >0 for a buffer with the given maximum size in bytes."
>
> Regarding the log we've, i hesitate between -1 or 0. Any preference? Any
> better way?
>
> FYI, we currently use the default configuration, knowing that the consumer
> is in Wildfly and the broker in a Spring Boot app. And artemis version is
> 1.5.5 on both sides, really old i know, sorry for this.
>
> Thanks in advance
>
> Kind regards
> Joseph PACHOD
> Staff Software Architect
> GE Healthcare
>
>