You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Jim Flowers (JIRA)" <ji...@apache.org> on 2011/08/29 19:04:38 UTC
[jira] [Created] (AMQ-3478) HTTP protocol w/remote client dropping
large messages
HTTP protocol w/remote client dropping large messages
-----------------------------------------------------
Key: AMQ-3478
URL: https://issues.apache.org/jira/browse/AMQ-3478
Project: ActiveMQ
Issue Type: Bug
Components: Transport
Affects Versions: 5.4.2
Environment: Windows Server 2008 (server) on internet, port 4001 open thru Windows Firewall, Win7 client home network wireless
Reporter: Jim Flowers
We're having a consistent problem using the HTTP transport on a machine hosted on the internet and accessed through a firewall. Tests using a client on same machine work. Tests in a private network with or without firewall work. Only part of our application is having problems, i.e., we can login to the app on the hosted machine and open a project; opening a larger dataset chunk-wise fails apparently due to activity timeout. Our message payload is serialized Java object graphs.
Have tried following:
1. setting wireFormat.maxInactivityDuration=0 (illegal param w/HTTP)
2. upping all socket timeouts to 30000
3. enabling TimeStampingBrokerPlugin
>From what we can see in the logs, in the remote case, the client sends several messages to fetch chunks of the large dataset which never arrive.
One thing we noticed in the activemq logs is a lot of removing and re-adding consumers. Not sure if that is a sign of a problem.
Here is a bit of the server log. The message jrflap-50115-1314636017162-1:1:3:17:1, came from the client asking for the chunk, and the server appears to send it, but the client logs has nothing.
begin server log snipit>>>>>>>>>>>>>>
2011-08-29 12:43:48,527 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:3:17:1 timestamp from 1314636216258 to 1314639828527
2011-08-29 12:43:48,527 [Thread-33 ] - TRACE ActiveMQMessageConsumer - ID:leonardo-50364-1314639588973-3:1:2:38 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:leonardo-50364-1314639588973-3:1:2:38, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, message = ActiveMQTextMessage {commandId = 97, responseRequired = true, messageId = ID:jrflap-50115-1314636017162-1:1:3:17:1, originalDestination = null, originalTransactionId = null, producerId = ID:jrflap-50115-1314636017162-1:1:3:17, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, transactionId = null, expiration = 0, timestamp = 1314639828527, arrival = 0, brokerInTime = 1314639828527, brokerOutTime = 1314639828527, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 1024, properties = {status=1}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = null}, redeliveryCounter = 0}
2011-08-29 12:43:48,543 [Thread-33 ] - DEBUG ActiveMQMessageConsumer - remove: ID:leonardo-50364-1314639588973-3:1:2:38, lastDeliveredSequenceId:640
2011-08-29 12:43:48,558 [qtp17691874-20 ] - DEBUG AbstractRegion - localhost removing consumer: ID:leonardo-50364-1314639588973-3:1:2:38 for destination: temp-topic://ID:leonardo-50364-1314639588973-3:1:1
2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - Expiring messages ..
2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - Expiring messages ..
2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
2011-08-29 12:43:49,666 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
2011-08-29 12:43:49,666 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
2011-08-29 12:43:50,009 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
2011-08-29 12:43:50,009 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
2011-08-29 12:43:50,508 [itor WriteCheck] - DEBUG InactivityMonitor - 9999 ms elapsed since last write check.
2011-08-29 12:43:50,508 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
2011-08-29 12:43:50,508 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
2011-08-29 12:43:50,508 [nitor ReadCheck] - TRACE InactivityMonitor - Message received since last read check, resetting flag:
2011-08-29 12:43:50,602 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
2011-08-29 12:43:50,602 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
2011-08-29 12:43:50,602 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
2011-08-29 12:43:50,602 [nitor ReadCheck] - TRACE InactivityMonitor - A receive is in progress
2011-08-29 12:43:51,007 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:1:2:1 timestamp from 1314636218740 to 1314639831007
2011-08-29 12:43:51,007 [MQ Session Task] - TRACE ActiveMQSession - ID:leonardo-50364-1314639588973-3:1:3 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:leonardo-50364-1314639588973-3:1:3:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:leonardo-50364-1314639588973-3:1:3:1, destination = topic://GPDCommunity.LGMDR_LIST, transactionId = null, expiration = 0, timestamp = 1314639831007, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {type=9}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = user1}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (AMQ-3478) HTTP protocol w/remote client
dropping large messages
Posted by "Timothy Bish (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/AMQ-3478?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13093015#comment-13093015 ]
Timothy Bish commented on AMQ-3478:
-----------------------------------
A JUnit test case reproducing the problem would help in getting someone to look into this. You might also want to try the newer version or a 5.6-SNAPSHOT build to see if the problem has already been addressed.
> HTTP protocol w/remote client dropping large messages
> -----------------------------------------------------
>
> Key: AMQ-3478
> URL: https://issues.apache.org/jira/browse/AMQ-3478
> Project: ActiveMQ
> Issue Type: Bug
> Components: Transport
> Affects Versions: 5.4.2
> Environment: Windows Server 2008 (server) on internet, port 4001 open thru Windows Firewall, Win7 client home network wireless
> Reporter: Jim Flowers
>
> We're having a consistent problem using the HTTP transport on a machine hosted on the internet and accessed through a firewall. Tests using a client on same machine work. Tests in a private network with or without firewall work. Only part of our application is having problems, i.e., we can login to the app on the hosted machine and open a project; opening a larger dataset chunk-wise fails apparently due to activity timeout. Our message payload is serialized Java object graphs.
> Have tried following:
> 1. setting wireFormat.maxInactivityDuration=0 (illegal param w/HTTP)
> 2. upping all socket timeouts to 30000
> 3. enabling TimeStampingBrokerPlugin
> From what we can see in the logs, in the remote case, the client sends several messages to fetch chunks of the large dataset which never arrive.
> One thing we noticed in the activemq logs is a lot of removing and re-adding consumers. Not sure if that is a sign of a problem.
> Here is a bit of the server log. The message jrflap-50115-1314636017162-1:1:3:17:1, came from the client asking for the chunk, and the server appears to send it, but the client logs has nothing.
> begin server log snipit>>>>>>>>>>>>>>
> 2011-08-29 12:43:48,527 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:3:17:1 timestamp from 1314636216258 to 1314639828527
> 2011-08-29 12:43:48,527 [Thread-33 ] - TRACE ActiveMQMessageConsumer - ID:leonardo-50364-1314639588973-3:1:2:38 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:leonardo-50364-1314639588973-3:1:2:38, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, message = ActiveMQTextMessage {commandId = 97, responseRequired = true, messageId = ID:jrflap-50115-1314636017162-1:1:3:17:1, originalDestination = null, originalTransactionId = null, producerId = ID:jrflap-50115-1314636017162-1:1:3:17, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, transactionId = null, expiration = 0, timestamp = 1314639828527, arrival = 0, brokerInTime = 1314639828527, brokerOutTime = 1314639828527, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 1024, properties = {status=1}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = null}, redeliveryCounter = 0}
> 2011-08-29 12:43:48,543 [Thread-33 ] - DEBUG ActiveMQMessageConsumer - remove: ID:leonardo-50364-1314639588973-3:1:2:38, lastDeliveredSequenceId:640
> 2011-08-29 12:43:48,558 [qtp17691874-20 ] - DEBUG AbstractRegion - localhost removing consumer: ID:leonardo-50364-1314639588973-3:1:2:38 for destination: temp-topic://ID:leonardo-50364-1314639588973-3:1:1
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,666 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:49,666 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,009 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,009 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [itor WriteCheck] - DEBUG InactivityMonitor - 9999 ms elapsed since last write check.
> 2011-08-29 12:43:50,508 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - TRACE InactivityMonitor - Message received since last read check, resetting flag:
> 2011-08-29 12:43:50,602 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,602 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - TRACE InactivityMonitor - A receive is in progress
> 2011-08-29 12:43:51,007 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:1:2:1 timestamp from 1314636218740 to 1314639831007
> 2011-08-29 12:43:51,007 [MQ Session Task] - TRACE ActiveMQSession - ID:leonardo-50364-1314639588973-3:1:3 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:leonardo-50364-1314639588973-3:1:3:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:leonardo-50364-1314639588973-3:1:3:1, destination = topic://GPDCommunity.LGMDR_LIST, transactionId = null, expiration = 0, timestamp = 1314639831007, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {type=9}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = user1}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (AMQ-3478) HTTP protocol w/remote client
dropping large messages
Posted by "Jim Flowers (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/AMQ-3478?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13093125#comment-13093125 ]
Jim Flowers commented on AMQ-3478:
----------------------------------
Hi,
Thanks for the quick reply. I'll look at the changelist for 5.5, but just moved to 5.4.2 for same reason to no effect. Coming up with a unit test to expose the error would be hard given our code, but not impossible. First, could we get some feedback from others who worked on the HTTP transport to see if this rings a bell? Clearly similar issues have been discussed w.r.t. TCP dropping large messages.
> HTTP protocol w/remote client dropping large messages
> -----------------------------------------------------
>
> Key: AMQ-3478
> URL: https://issues.apache.org/jira/browse/AMQ-3478
> Project: ActiveMQ
> Issue Type: Bug
> Components: Transport
> Affects Versions: 5.4.2
> Environment: Windows Server 2008 (server) on internet, port 4001 open thru Windows Firewall, Win7 client home network wireless
> Reporter: Jim Flowers
>
> We're having a consistent problem using the HTTP transport on a machine hosted on the internet and accessed through a firewall. Tests using a client on same machine work. Tests in a private network with or without firewall work. Only part of our application is having problems, i.e., we can login to the app on the hosted machine and open a project; opening a larger dataset chunk-wise fails apparently due to activity timeout. Our message payload is serialized Java object graphs.
> Have tried following:
> 1. setting wireFormat.maxInactivityDuration=0 (illegal param w/HTTP)
> 2. upping all socket timeouts to 30000
> 3. enabling TimeStampingBrokerPlugin
> From what we can see in the logs, in the remote case, the client sends several messages to fetch chunks of the large dataset which never arrive.
> One thing we noticed in the activemq logs is a lot of removing and re-adding consumers. Not sure if that is a sign of a problem.
> Here is a bit of the server log. The message jrflap-50115-1314636017162-1:1:3:17:1, came from the client asking for the chunk, and the server appears to send it, but the client logs has nothing.
> begin server log snipit>>>>>>>>>>>>>>
> 2011-08-29 12:43:48,527 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:3:17:1 timestamp from 1314636216258 to 1314639828527
> 2011-08-29 12:43:48,527 [Thread-33 ] - TRACE ActiveMQMessageConsumer - ID:leonardo-50364-1314639588973-3:1:2:38 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:leonardo-50364-1314639588973-3:1:2:38, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, message = ActiveMQTextMessage {commandId = 97, responseRequired = true, messageId = ID:jrflap-50115-1314636017162-1:1:3:17:1, originalDestination = null, originalTransactionId = null, producerId = ID:jrflap-50115-1314636017162-1:1:3:17, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, transactionId = null, expiration = 0, timestamp = 1314639828527, arrival = 0, brokerInTime = 1314639828527, brokerOutTime = 1314639828527, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 1024, properties = {status=1}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = null}, redeliveryCounter = 0}
> 2011-08-29 12:43:48,543 [Thread-33 ] - DEBUG ActiveMQMessageConsumer - remove: ID:leonardo-50364-1314639588973-3:1:2:38, lastDeliveredSequenceId:640
> 2011-08-29 12:43:48,558 [qtp17691874-20 ] - DEBUG AbstractRegion - localhost removing consumer: ID:leonardo-50364-1314639588973-3:1:2:38 for destination: temp-topic://ID:leonardo-50364-1314639588973-3:1:1
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,666 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:49,666 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,009 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,009 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [itor WriteCheck] - DEBUG InactivityMonitor - 9999 ms elapsed since last write check.
> 2011-08-29 12:43:50,508 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - TRACE InactivityMonitor - Message received since last read check, resetting flag:
> 2011-08-29 12:43:50,602 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,602 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - TRACE InactivityMonitor - A receive is in progress
> 2011-08-29 12:43:51,007 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:1:2:1 timestamp from 1314636218740 to 1314639831007
> 2011-08-29 12:43:51,007 [MQ Session Task] - TRACE ActiveMQSession - ID:leonardo-50364-1314639588973-3:1:3 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:leonardo-50364-1314639588973-3:1:3:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:leonardo-50364-1314639588973-3:1:3:1, destination = topic://GPDCommunity.LGMDR_LIST, transactionId = null, expiration = 0, timestamp = 1314639831007, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {type=9}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = user1}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Closed] (AMQ-3478) HTTP protocol w/remote client dropping
large messages
Posted by "Timothy Bish (Closed) (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/AMQ-3478?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Timothy Bish closed AMQ-3478.
-----------------------------
Resolution: Incomplete
Need a unit test to reproduce the issue, current tests all pass. No other reports of this problem so far so a working test would be key to figuring out if there's an issue.
> HTTP protocol w/remote client dropping large messages
> -----------------------------------------------------
>
> Key: AMQ-3478
> URL: https://issues.apache.org/jira/browse/AMQ-3478
> Project: ActiveMQ
> Issue Type: Bug
> Components: Transport
> Affects Versions: 5.4.2
> Environment: Windows Server 2008 (server) on internet, port 4001 open thru Windows Firewall, Win7 client home network wireless
> Reporter: Jim Flowers
>
> We're having a consistent problem using the HTTP transport on a machine hosted on the internet and accessed through a firewall. Tests using a client on same machine work. Tests in a private network with or without firewall work. Only part of our application is having problems, i.e., we can login to the app on the hosted machine and open a project; opening a larger dataset chunk-wise fails apparently due to activity timeout. Our message payload is serialized Java object graphs.
> Have tried following:
> 1. setting wireFormat.maxInactivityDuration=0 (illegal param w/HTTP)
> 2. upping all socket timeouts to 30000
> 3. enabling TimeStampingBrokerPlugin
> From what we can see in the logs, in the remote case, the client sends several messages to fetch chunks of the large dataset which never arrive.
> One thing we noticed in the activemq logs is a lot of removing and re-adding consumers. Not sure if that is a sign of a problem.
> Here is a bit of the server log. The message jrflap-50115-1314636017162-1:1:3:17:1, came from the client asking for the chunk, and the server appears to send it, but the client logs has nothing.
> begin server log snipit>>>>>>>>>>>>>>
> 2011-08-29 12:43:48,527 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:3:17:1 timestamp from 1314636216258 to 1314639828527
> 2011-08-29 12:43:48,527 [Thread-33 ] - TRACE ActiveMQMessageConsumer - ID:leonardo-50364-1314639588973-3:1:2:38 received message: MessageDispatch {commandId = 0, responseRequired = false, consumerId = ID:leonardo-50364-1314639588973-3:1:2:38, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, message = ActiveMQTextMessage {commandId = 97, responseRequired = true, messageId = ID:jrflap-50115-1314636017162-1:1:3:17:1, originalDestination = null, originalTransactionId = null, producerId = ID:jrflap-50115-1314636017162-1:1:3:17, destination = temp-topic://ID:leonardo-50364-1314639588973-3:1:1, transactionId = null, expiration = 0, timestamp = 1314639828527, arrival = 0, brokerInTime = 1314639828527, brokerOutTime = 1314639828527, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 1024, properties = {status=1}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = null}, redeliveryCounter = 0}
> 2011-08-29 12:43:48,543 [Thread-33 ] - DEBUG ActiveMQMessageConsumer - remove: ID:leonardo-50364-1314639588973-3:1:2:38, lastDeliveredSequenceId:640
> 2011-08-29 12:43:48,558 [qtp17691874-20 ] - DEBUG AbstractRegion - localhost removing consumer: ID:leonardo-50364-1314639588973-3:1:2:38 for destination: temp-topic://ID:leonardo-50364-1314639588973-3:1:1
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,369 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,369 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - Expiring messages ..
> 2011-08-29 12:43:49,385 [host] Scheduler] - DEBUG Queue - TEST.QUEUE toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,385 [host] Scheduler] - TRACE AbstractStoreCursor - fillBatch - batchResetNeeded=false, hasMessages=false, size=0
> 2011-08-29 12:43:49,666 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:49,666 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,009 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,009 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [itor WriteCheck] - DEBUG InactivityMonitor - 9999 ms elapsed since last write check.
> 2011-08-29 12:43:50,508 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,508 [nitor ReadCheck] - TRACE InactivityMonitor - Message received since last read check, resetting flag:
> 2011-08-29 12:43:50,602 [itor WriteCheck] - DEBUG InactivityMonitor - 10000 ms elapsed since last write check.
> 2011-08-29 12:43:50,602 [itor WriteCheck] - TRACE InactivityMonitor - Message sent since last write check, resetting flag
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - DEBUG InactivityMonitor - 29999 ms elapsed since last read check.
> 2011-08-29 12:43:50,602 [nitor ReadCheck] - TRACE InactivityMonitor - A receive is in progress
> 2011-08-29 12:43:51,007 [qtp17691874-97 ] - DEBUG TimeStampingBrokerPlugin - Set message ID:jrflap-50115-1314636017162-1:1:1:2:1 timestamp from 1314636218740 to 1314639831007
> 2011-08-29 12:43:51,007 [MQ Session Task] - TRACE ActiveMQSession - ID:leonardo-50364-1314639588973-3:1:3 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:leonardo-50364-1314639588973-3:1:3:1:3, originalDestination = null, originalTransactionId = null, producerId = ID:leonardo-50364-1314639588973-3:1:3:1, destination = topic://GPDCommunity.LGMDR_LIST, transactionId = null, expiration = 0, timestamp = 1314639831007, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {type=9}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = user1}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira