[
https://issues.apache.org/jira/browse/AMQ-4996?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13890470#comment-13890470
]
Jonathan Graham commented on AMQ-4996:
--------------------------------------
During the 5 seconds between the start of the send and the receipt of the
timeout, the broker log is showing me that background things are happening. For
example, I got a timeout at 05:08:48 (send started at 05:05:43) and the log
looks like this:
28/01/2014 05:08:42,536 (Thread-38) DEBUG : Stopping transport
tcp://localhost.localdomain/127.0.0.1:2348
28/01/2014 05:08:42,536 (ActiveMQ Task-15799) DEBUG : Stopping connection:
/127.0.0.1:35791
28/01/2014 05:08:42,537 (ActiveMQ Task-15799) DEBUG : Stopping transport
tcp:///127.0.0.1:35791
28/01/2014 05:08:42,538 (ActiveMQ Task-15799) DEBUG : Stopped transport:
/127.0.0.1:35791
28/01/2014 05:08:42,539 (ActiveMQ Task-15799) DEBUG : Connection Stopped:
/127.0.0.1:35791
28/01/2014 05:08:45,464 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@46fff62d 9999 ms elapsed
since last write check.
28/01/2014 05:08:45,653 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@3f65bc68 10001 ms elapsed
since last write check.
28/01/2014 05:08:45,753 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@48ba57c4 10001 ms elapsed
since last write check.
28/01/2014 05:08:45,905 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@c28a9ee 10001 ms elapsed
since last write check.
28/01/2014 05:08:45,982 (ActiveMQ Journal Checkpoint Worker) DEBUG : Checkpoint
started.
28/01/2014 05:08:47,105 (InactivityMonitor ReadCheck) DEBUG : 29999 ms elapsed
since last read check.
28/01/2014 05:08:47,106 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@4c28b3c3 10001 ms elapsed
since last write check.
28/01/2014 05:08:47,295 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@41383426 10000 ms elapsed
since last write check.
28/01/2014 05:08:47,295 (InactivityMonitor ReadCheck) DEBUG : 29999 ms elapsed
since last read check.
28/01/2014 05:08:49,563 (InactivityMonitor ReadCheck) DEBUG : 30000 ms elapsed
since last read check.
28/01/2014 05:08:49,563 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@6f18ba62 10000 ms elapsed
since last write check.
28/01/2014 05:08:49,638 (InactivityMonitor ReadCheck) DEBUG : 29999 ms elapsed
since last read check.
28/01/2014 05:08:49,638 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@2d1624be 10001 ms elapsed
since last write check.
28/01/2014 05:08:50,665 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@751e1ab5 10002 ms elapsed
since last write check.
28/01/2014 05:08:50,862 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@60d96f5b 10000 ms elapsed
since last write check.
28/01/2014 05:08:51,171 (InactivityMonitor WriteCheck) DEBUG :
org.apache.activemq.transport.InactivityMonitor$2@6bf450a5 10001 ms elapsed
since last write check.
28/01/2014 05:08:51,268 (ActiveMQ Journal Checkpoint Worker) DEBUG : Checkpoint
done.
28/01/2014 05:08:51,771 (ActiveMQ Journal Checkpoint Worker) DEBUG : Checkpoint
started.
28/01/2014 05:08:51,798 (ActiveMQ Journal Checkpoint Worker) DEBUG : Checkpoint
done.
Any insight would be helpful!
Thanks
> org.apache.activemq.transport.RequestTimedOutIOException thrown by
> producer.send() for no obvious reason. Message is actually sent.
> -----------------------------------------------------------------------------------------------------------------------------------
>
> Key: AMQ-4996
> URL: https://issues.apache.org/jira/browse/AMQ-4996
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker, JMS client
> Affects Versions: 5.5.1
> Environment: Redhat Linux
> Reporter: Jonathan Graham
>
> In production we are getting
> org.apache.activemq.transport.RequestTimedOutIOException exceptions thrown
> sometimes when we execute the send command. The timeout is set to 5 seconds
> and it blocks for 5 seconds and then throws the exception. The message is
> actually sent to the broker successfully (I don't know if it's sent
> immediately or if there was a delay before it gets there).
> We are communicating with the broker via TCP but it is on the localhost.
> This happens 'every so often' with no explanation that I can find. No errors
> appear in the broker logs (and no clues when configured to DEBUG level). The
> volume is very low; a message every 20-30 seconds or so, and they are
> immediately handled by a consumer - the broker has not run out of storage or
> memory.
> It seems to happen in bursts (e.g. it happened 4 times within 10 minutes, but
> not on every message, and then didn't happen again all day).
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
