activemq-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jiri Danek (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (ARTEMIS-1317) Messages that expire on OpenWire client are lost (never make it to ExpiryQueue, if one is configured)
Date Fri, 11 Aug 2017 07:16:00 GMT

     [ https://issues.apache.org/jira/browse/ARTEMIS-1317?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Jiri Danek updated ARTEMIS-1317:
--------------------------------
    Fix Version/s: 2.3.0

> Messages that expire on OpenWire client are lost (never make it to ExpiryQueue, if one
is configured)
> -----------------------------------------------------------------------------------------------------
>
>                 Key: ARTEMIS-1317
>                 URL: https://issues.apache.org/jira/browse/ARTEMIS-1317
>             Project: ActiveMQ Artemis
>          Issue Type: Bug
>          Components: Broker, OpenWire
>    Affects Versions: 2.2.0, 2.3.0
>            Reporter: Jiri Danek
>            Priority: Critical
>             Fix For: 2.3.0
>
>
> The scenario is tested by an openwire test from activemq5, which is currently failing.
> {noformat}
> Running org.apache.activemq.JmsSendReceiveWithMessageExpirationTest
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:22,905 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: null flag: false
> 2017-08-01 08:40:22,905 [main           ] - INFO  TcpTransportFactory            - starting
internal broker: tcp://localhost:61616
> 2017-08-01 08:40:22,905 [main           ] - INFO  ArtemisBrokerHelper            - ---starting
broker, service is there? null
> 2017-08-01 08:40:22,905 [main           ] - INFO  BrokerService                  - Apache
ActiveMQ Artemis Wrapper 5.14.0 (localhost, Artemis Broker) is starting
> acceptor =>: TransportConfiguration(name=home, factory=org-apache-activemq-artemis-core-remoting-impl-netty-NettyAcceptorFactory)
?port=61616&host=localhost
> [main] 08:40:22,906 INFO  [org.apache.activemq.artemis.core.server] AMQ221000: live Message
Broker is starting with configuration Broker Configuration (clustered=false,journalDirectory=/root/workspace/peline_jdanek_artemis_junit-MXKODGBZMK2IRSU3ZGP3WXI5HYEVJ64OU2VN7HHODGYVOJ5FA7IQ/tests/activemq5-unit-tests/./target/tmp/junit5554952782813333836/journal,bindingsDirectory=/root/workspace/peline_jdanek_artemis_junit-MXKODGBZMK2IRSU3ZGP3WXI5HYEVJ64OU2VN7HHODGYVOJ5FA7IQ/tests/activemq5-unit-tests/./target/tmp/junit5554952782813333836/bindings,largeMessagesDirectory=/root/workspace/peline_jdanek_artemis_junit-MXKODGBZMK2IRSU3ZGP3WXI5HYEVJ64OU2VN7HHODGYVOJ5FA7IQ/tests/activemq5-unit-tests/./target/tmp/junit5554952782813333836/large-msg,pagingDirectory=/root/workspace/peline_jdanek_artemis_junit-MXKODGBZMK2IRSU3ZGP3WXI5HYEVJ64OU2VN7HHODGYVOJ5FA7IQ/tests/activemq5-unit-tests/./target/tmp/junit5554952782813333836/page)
> [main] 08:40:22,906 INFO  [org.apache.activemq.artemis.core.server] AMQ221057: Global
Max Size is being adjusted to 1/2 of the JVM max size (-Xmx). being defined as 1,851,260,928
> [main] 08:40:22,906 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol
module found: [artemis-server]. Adding protocol support for: CORE
> [main] 08:40:22,907 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol
module found: [artemis-openwire-protocol]. Adding protocol support for: OPENWIRE
> [main] 08:40:22,907 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol
module found: [artemis-stomp-protocol]. Adding protocol support for: STOMP
> [main] 08:40:22,910 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started
EPOLL Acceptor at localhost:61616 for protocols [CORE,STOMP,OPENWIRE]
> [main] 08:40:22,910 INFO  [org.apache.activemq.artemis.core.server] AMQ221007: Server
is now live
> [main] 08:40:22,910 INFO  [org.apache.activemq.artemis.core.server] AMQ221001: Apache
ActiveMQ Artemis Message Broker version 2.3.0-SNAPSHOT [localhost, nodeID=95e57e85-76b6-11e7-aa4e-fa163e5a2b31]

> 2017-08-01 08:40:22,910 [main           ] - INFO  BrokerService                  - Apache
ActiveMQ Artemis Wrapper 5.14.0 (localhost, Artemis Broker) started
> 2017-08-01 08:40:22,910 [main           ] - INFO  BrokerService                  - For
help or more information please see: http://activemq.apache.org
> 2017-08-01 08:40:22,910 [main           ] - INFO  ArtemisBrokerHelper            - started
a service instance: BrokerService[localhost]org.apache.activemq.broker.BrokerService@47a71f54
> 2017-08-01 08:40:22,910 [main           ] - INFO  TcpTransportFactory            - just
created tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
> 2017-08-01 08:40:22,910 [main           ] - INFO  TcpTransportFactory            - bound:
localhost
> xxxxxxxxxxxx created transporttcp://localhost:61616
> 2017-08-01 08:40:22,934 [main           ] - INFO  ceiveWithMessageExpirationTest - Dumping
stats...
> 2017-08-01 08:40:22,934 [main           ] - INFO  ceiveWithMessageExpirationTest - Closing
down connection
> [Thread-1 (activemq-netty-threads)] 08:40:22,935 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session 95e68ff6-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-1 (activemq-netty-threads)] 08:40:22,935 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session 95e68ff6-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-1 (activemq-netty-threads)] 08:40:22,935 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-807:1:-1
> [Thread-1 (activemq-netty-threads)] 08:40:22,935 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-807:1:-1
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:22,937 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
flag: false
> xxxxxxxxxxxx created transporttcp://localhost:61616
> 2017-08-01 08:40:22,975 [main           ] - INFO  ceiveWithMessageExpirationTest - Dumping
stats...
> 2017-08-01 08:40:22,976 [main           ] - INFO  ceiveWithMessageExpirationTest - Closing
down connection
> [Thread-2 (activemq-netty-threads)] 08:40:22,976 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session 95ea608a-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-2 (activemq-netty-threads)] 08:40:22,977 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session 95ea608a-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-2 (activemq-netty-threads)] 08:40:22,977 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-809:1:-1
> [Thread-2 (activemq-netty-threads)] 08:40:22,977 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-809:1:-1
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:22,980 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
flag: false
> xxxxxxxxxxxx created transporttcp://localhost:61616
> 2017-08-01 08:40:30,014 [main           ] - INFO  ceiveWithMessageExpirationTest - Dumping
stats...
> 2017-08-01 08:40:30,014 [main           ] - INFO  ceiveWithMessageExpirationTest - Closing
down connection
> [Thread-3 (activemq-netty-threads)] 08:40:30,015 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session 95f13e5e-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-3 (activemq-netty-threads)] 08:40:30,015 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session 95f13e5e-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-3 (activemq-netty-threads)] 08:40:30,015 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-811:1:-1
> [Thread-3 (activemq-netty-threads)] 08:40:30,015 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-811:1:-1
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:30,017 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
flag: false
> xxxxxxxxxxxx created transporttcp://localhost:61616
> 2017-08-01 08:40:37,049 [main           ] - INFO  ceiveWithMessageExpirationTest - Dumping
stats...
> 2017-08-01 08:40:37,049 [main           ] - INFO  ceiveWithMessageExpirationTest - Closing
down connection
> [Thread-4 (activemq-netty-threads)] 08:40:37,049 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session 9a22da22-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-4 (activemq-netty-threads)] 08:40:37,050 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session 9a22da22-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-4 (activemq-netty-threads)] 08:40:37,050 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-813:1:-1
> [Thread-4 (activemq-netty-threads)] 08:40:37,050 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-813:1:-1
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:37,053 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
flag: false
> xxxxxxxxxxxx created transporttcp://localhost:61616
> xxxxxcreating conn: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false
> 2017-08-01 08:40:37,058 [main           ] - INFO  TcpTransportFactory            - deciding
whether starting an internal broker: tcp://localhost:61616?invmBrokerId=localhost&broker.persistent=false@1501591222910
flag: false
> xxxxxxxxxxxx created transporttcp://localhost:61616
> 2017-08-01 08:40:40,284 [main           ] - INFO  ceiveWithMessageExpirationTest - Dumping
stats...
> 2017-08-01 08:40:40,284 [main           ] - INFO  ceiveWithMessageExpirationTest - Closing
down connection
> [Thread-5 (activemq-netty-threads)] 08:40:40,285 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session 9e544ed6-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-5 (activemq-netty-threads)] 08:40:40,285 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session 9e544ed6-76b6-11e7-aa4e-fa163e5a2b31
> [Thread-5 (activemq-netty-threads)] 08:40:40,285 WARN  [org.apache.activemq.artemis.core.server]
AMQ222061: Client connection failed, clearing up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-815:1:-1
> [Thread-5 (activemq-netty-threads)] 08:40:40,285 WARN  [org.apache.activemq.artemis.core.server]
AMQ222107: Cleared up resources for session ID:host-172-0-0-126.openstacklocal-39842-1501590872918-815:1:-1
> Tests run: 5, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 17.381 sec <<<
FAILURE! - in org.apache.activemq.JmsSendReceiveWithMessageExpirationTest
> testConsumeExpiredQueueAndDlq(org.apache.activemq.JmsSendReceiveWithMessageExpirationTest)
 Time elapsed: 3.235 sec  <<< FAILURE!
> junit.framework.AssertionFailedError: got dlq messages expected:<99> but was:<90>
> 	at junit.framework.Assert.fail(Assert.java:57)
> 	at junit.framework.Assert.failNotEquals(Assert.java:329)
> 	at junit.framework.Assert.assertEquals(Assert.java:78)
> 	at junit.framework.Assert.assertEquals(Assert.java:234)
> 	at junit.framework.TestCase.assertEquals(TestCase.java:401)
> 	at org.apache.activemq.JmsSendReceiveWithMessageExpirationTest.testConsumeExpiredQueueAndDlq(JmsSendReceiveWithMessageExpirationTest.java:164)
> {noformat}
> I've discussed the test with Clebert at ARTEMIS-1276 (https://github.com/apache/activemq-artemis/pull/1407)
> IMO, the reason for the assertion error is that the client's prefetch value is 10 messages,
out of which 1 message is consumed immediately (on time), while the remaining 9 messages are
left to expire in the prefetch cache.
> The test then tries to get the expired messages from ExpiryQueue, but gets only 90 that
expired on the server. The 9 that expired on client are missing.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message