Paul Gallagher created ARTEMIS-837:
--------------------------------------
Summary: 'Replicated Transaction Failover Example' is failing
Key: ARTEMIS-837
URL: https://issues.apache.org/jira/browse/ARTEMIS-837
Project: ActiveMQ Artemis
Issue Type: Bug
Affects Versions: 1.6.0
Environment: Fedora 24
maven 3.2.3
Oracle JDK 8
Reporter: Paul Gallagher
Fix For: 1.6.0
This is the full output from the example run, it is repeatable
[INFO] --- artemis-maven-plugin:1.6.0-SNAPSHOT:runClient (runClient) @
replicated-transaction-failover ---
ReplicatedTransactionFailoverExample0-out: _ _ _
ReplicatedTransactionFailoverExample0-out: / \ ____| |_ ___ __ __(_) _____
ReplicatedTransactionFailoverExample0-out: / _ \| _ \ __|/ _ \ \/ | |/ __/
ReplicatedTransactionFailoverExample0-out: / ___ \ | \/ |_/ __/ |\/| | |\___ \
ReplicatedTransactionFailoverExample0-out: /_/ \_\| \__\____|_| |_|_|/___ /
ReplicatedTransactionFailoverExample0-out: Apache ActiveMQ Artemis
1.6.0-SNAPSHOT
ReplicatedTransactionFailoverExample0-out:
ReplicatedTransactionFailoverExample0-out:
ReplicatedTransactionFailoverExample0-out:11:43:58,529 INFO
[org.apache.activemq.artemis.integration.bootstrap] AMQ101000: Starting
ActiveMQ Artemis Server
awaiting server tcp://localhost:61616 start at
ReplicatedTransactionFailoverExample0-out:11:43:58,659 INFO
[org.apache.activemq.artemis.core.server] AMQ221000: live Message Broker is
starting with configuration Broker Configuration
(clustered=true,journalDirectory=./data/journal,bindingsDirectory=./data/bindings,largeMessagesDirectory=./data/largemessages,pagingDirectory=./data/paging)
ReplicatedTransactionFailoverExample0-out:11:43:58,677 INFO
[org.apache.activemq.artemis.core.server] AMQ221012: Using AIO Journal
ReplicatedTransactionFailoverExample0-out:11:43:58,699 WARN
[org.apache.activemq.artemis.core.server] AMQ222007: Security risk! Apache
ActiveMQ Artemis is running with the default cluster admin user and default
password. Please see the cluster chapter in the ActiveMQ Artemis User Guide for
instructions on how to change this.
ReplicatedTransactionFailoverExample0-out:11:43:58,731 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-server]. Adding protocol support for: CORE
ReplicatedTransactionFailoverExample0-out:11:43:58,732 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-amqp-protocol]. Adding protocol support for: AMQP
ReplicatedTransactionFailoverExample0-out:11:43:58,734 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-hornetq-protocol]. Adding protocol support for: HORNETQ
ReplicatedTransactionFailoverExample0-out:11:43:58,735 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-mqtt-protocol]. Adding protocol support for: MQTT
ReplicatedTransactionFailoverExample0-out:11:43:58,735 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-openwire-protocol]. Adding protocol support for: OPENWIRE
ReplicatedTransactionFailoverExample0-out:11:43:58,736 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-stomp-protocol]. Adding protocol support for: STOMP
awaiting server tcp://localhost:61616 start at
awaiting server tcp://localhost:61616 start at
ReplicatedTransactionFailoverExample0-out:11:43:59,748 INFO
[org.apache.activemq.artemis.core.server] AMQ221003: Deploying queue
jms.queue.exampleQueue
ReplicatedTransactionFailoverExample0-out:11:43:59,776 WARN
[org.apache.activemq.artemis.core.server] AMQ222165: No Dead Letter Address
configured for queue jms.queue.exampleQueue in AddressSettings
ReplicatedTransactionFailoverExample0-out:11:43:59,776 WARN
[org.apache.activemq.artemis.core.server] AMQ222166: No Expiry Address
configured for queue jms.queue.exampleQueue in AddressSettings
awaiting server tcp://localhost:61616 start at
awaiting server tcp://localhost:61616 start at
awaiting server tcp://localhost:61616 start at
awaiting server tcp://localhost:61616 start at
ReplicatedTransactionFailoverExample0-out:11:44:01,715 INFO
[org.apache.activemq.artemis.core.server] AMQ221020: Started Acceptor at
localhost:61616 for protocols [CORE,MQTT,AMQP,HORNETQ,STOMP,OPENWIRE]
ReplicatedTransactionFailoverExample0-out:11:44:01,716 INFO
[org.apache.activemq.artemis.core.server] AMQ221007: Server is now live
ReplicatedTransactionFailoverExample0-out:11:44:01,716 INFO
[org.apache.activemq.artemis.core.server] AMQ221001: Apache ActiveMQ Artemis
Message Broker version 1.6.0-SNAPSHOT [localhost,
nodeID=f92bc6bf-a283-11e6-8c31-e82aea237814]
server tcp://localhost:61616 started
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
ReplicatedTransactionFailoverExample1-out: _ _ _
ReplicatedTransactionFailoverExample1-out: / \ ____| |_ ___ __ __(_) _____
ReplicatedTransactionFailoverExample1-out: / _ \| _ \ __|/ _ \ \/ | |/ __/
ReplicatedTransactionFailoverExample1-out: / ___ \ | \/ |_/ __/ |\/| | |\___ \
ReplicatedTransactionFailoverExample1-out: /_/ \_\| \__\____|_| |_|_|/___ /
ReplicatedTransactionFailoverExample1-out: Apache ActiveMQ Artemis
1.6.0-SNAPSHOT
ReplicatedTransactionFailoverExample1-out:
ReplicatedTransactionFailoverExample1-out:
ReplicatedTransactionFailoverExample1-out:11:44:02,825 INFO
[org.apache.activemq.artemis.integration.bootstrap] AMQ101000: Starting
ActiveMQ Artemis Server
ReplicatedTransactionFailoverExample1-out:11:44:02,948 INFO
[org.apache.activemq.artemis.core.server] AMQ221000: backup Message Broker is
starting with configuration Broker Configuration
(clustered=true,journalDirectory=./data/journal,bindingsDirectory=./data/bindings,largeMessagesDirectory=./data/largemessages,pagingDirectory=./data/paging)
ReplicatedTransactionFailoverExample1-out:11:44:02,959 INFO
[org.apache.activemq.artemis.core.server] AMQ222162: Moving data directory
/home/pgallagh/Work/AMQ7/rh-messaging/external/apache-activemq-artemis/examples/features/ha/replicated-transaction-failover/target/server1/./data/journal
to
/home/pgallagh/Work/AMQ7/rh-messaging/external/apache-activemq-artemis/examples/features/ha/replicated-transaction-failover/target/server1/./data/journal/oldreplica.1
ReplicatedTransactionFailoverExample1-out:11:44:02,981 INFO
[org.apache.activemq.artemis.core.server] AMQ221012: Using AIO Journal
ReplicatedTransactionFailoverExample1-out:11:44:03,007 WARN
[org.apache.activemq.artemis.core.server] AMQ222007: Security risk! Apache
ActiveMQ Artemis is running with the default cluster admin user and default
password. Please see the cluster chapter in the ActiveMQ Artemis User Guide for
instructions on how to change this.
ReplicatedTransactionFailoverExample1-out:11:44:03,045 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-server]. Adding protocol support for: CORE
ReplicatedTransactionFailoverExample1-out:11:44:03,046 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-amqp-protocol]. Adding protocol support for: AMQP
ReplicatedTransactionFailoverExample1-out:11:44:03,048 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-hornetq-protocol]. Adding protocol support for: HORNETQ
ReplicatedTransactionFailoverExample1-out:11:44:03,049 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-mqtt-protocol]. Adding protocol support for: MQTT
ReplicatedTransactionFailoverExample1-out:11:44:03,052 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-openwire-protocol]. Adding protocol support for: OPENWIRE
ReplicatedTransactionFailoverExample1-out:11:44:03,053 INFO
[org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found:
[artemis-stomp-protocol]. Adding protocol support for: STOMP
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
ReplicatedTransactionFailoverExample1-out:11:44:05,239 INFO
[org.apache.activemq.artemis.core.server] AMQ221109: Apache ActiveMQ Artemis
Backup Server version 1.6.0-SNAPSHOT [null] started, waiting live to fail
before it gets active
awaiting server tcp://localhost:61617 start at
ReplicatedTransactionFailoverExample0-out:11:44:06,157 INFO
[org.apache.activemq.artemis.core.server] AMQ221025: Replication: sending
JournalFileImpl: (activemq-data-2.amq id = 2, recordID = 2) (size=10,485,760)
to backup.
AIOSequentialFile:/home/pgallagh/Work/AMQ7/rh-messaging/external/apache-activemq-artemis/examples/features/ha/replicated-transaction-failover/target/server0/./data/journal/activemq-data-2.amq
awaiting server tcp://localhost:61617 start at
awaiting server tcp://localhost:61617 start at
Sent message: This is text message 0
Sent message: This is text message 1
Sent message: This is text message 2
Sent message: This is text message 3
Sent message: This is text message 4
**********************************
Killing server java.lang.UNIXProcess@138f2646
**********************************
ReplicatedTransactionFailoverExample1-out:11:44:07,667 WARN
[org.apache.activemq.artemis.journal] File not opened, file=null:
java.lang.NullPointerException: File not opened, file=null
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.aio.AIOSequentialFile.checkOpened(AIOSequentialFile.java:290)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.aio.AIOSequentialFile.writeDirect(AIOSequentialFile.java:204)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.AbstractSequentialFile$LocalBufferObserver.flushBuffer(AbstractSequentialFile.java:297)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.buffer.TimedBuffer.flush(TimedBuffer.java:286)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.buffer.TimedBuffer.flush(TimedBuffer.java:258)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.AbstractSequentialFileFactory.flush(AbstractSequentialFileFactory.java:161)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.flush(JournalImpl.java:2070)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.stop(JournalImpl.java:2257)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.persistence.impl.journal.JournalStorageManager.stop(JournalStorageManager.java:239)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.persistence.impl.journal.JournalStorageManager.stop(JournalStorageManager.java:178)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.stop(ReplicationEndpoint.java:319)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.stopComponent(ActiveMQServerImpl.java:1037)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.SharedNothingBackupActivation.run(SharedNothingBackupActivation.java:248)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$ActivationThread.run(ActiveMQServerImpl.java:2415)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out:
ReplicatedTransactionFailoverExample1-out:11:44:07,668 WARN
[org.apache.activemq.artemis.journal] AMQ142027: Error on writing data! File
not opened, file=null code - -1: java.lang.Exception: File not opened, file=null
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.DummyCallback.onError(DummyCallback.java:36)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.AbstractSequentialFile$DelegateCallback.onError(AbstractSequentialFile.java:271)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.aio.AIOSequentialFile.writeDirect(AIOSequentialFile.java:207)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.AbstractSequentialFile$LocalBufferObserver.flushBuffer(AbstractSequentialFile.java:297)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.buffer.TimedBuffer.flush(TimedBuffer.java:286)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.buffer.TimedBuffer.flush(TimedBuffer.java:258)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.io.AbstractSequentialFileFactory.flush(AbstractSequentialFileFactory.java:161)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.flush(JournalImpl.java:2070)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.stop(JournalImpl.java:2257)
[artemis-journal-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.persistence.impl.journal.JournalStorageManager.stop(JournalStorageManager.java:239)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.persistence.impl.journal.JournalStorageManager.stop(JournalStorageManager.java:178)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.stop(ReplicationEndpoint.java:319)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.stopComponent(ActiveMQServerImpl.java:1037)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.SharedNothingBackupActivation.run(SharedNothingBackupActivation.java:248)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out: at
org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$ActivationThread.run(ActiveMQServerImpl.java:2415)
[artemis-server-1.6.0-SNAPSHOT.jar:1.6.0-SNAPSHOT]
ReplicatedTransactionFailoverExample1-out:
Nov 04, 2016 11:44:07 AM
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl fail
WARN: AMQ212037: Connection failure has been detected: AMQ119015: The
connection was disconnected because of server shutdown [code=DISCONNECTED]
ReplicatedTransactionFailoverExample1-out:11:44:07,683 WARN
[org.apache.activemq.artemis.core.client] AMQ212037: Connection failure has
been detected: AMQ119015: The connection was disconnected because of server
shutdown [code=DISCONNECTED]
ReplicatedTransactionFailoverExample1-out:11:44:07,700 WARN
[org.apache.activemq.artemis.core.client] AMQ212004: Failed to connect to
server.
ReplicatedTransactionFailoverExample1-out:11:44:07,874 INFO
[org.apache.activemq.artemis.core.server] AMQ221002: Apache ActiveMQ Artemis
Message Broker version 1.6.0-SNAPSHOT [f92bc6bf-a283-11e6-8c31-e82aea237814]
stopped, uptime 5.046 seconds
Sent message: This is text message 5
Sent message: This is text message 6
Sent message: This is text message 7
Sent message: This is text message 8
Sent message: This is text message 9
Nov 04, 2016 11:48:09 AM
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl
reconnectSessions
WARN: AMQ212004: Failed to connect to server.
**********************************
Killing server java.lang.UNIXProcess@138f2646
**********************************
**********************************
Killing server java.lang.UNIXProcess@5c28d9b
**********************************
[ERROR]
java.lang.reflect.InvocationTargetException
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.apache.activemq.artemis.maven.ArtemisClientPlugin.doExecute(ArtemisClientPlugin.java:61)
at
org.apache.activemq.artemis.maven.ArtemisAbstractPlugin.execute(ArtemisAbstractPlugin.java:71)
at
org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:132)
at
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:208)
at
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
at
org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
at
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
at
org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
at
org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
at
org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:120)
at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:347)
at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:154)
at org.apache.maven.cli.MavenCli.execute(MavenCli.java:582)
at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:214)
at org.apache.maven.cli.MavenCli.main(MavenCli.java:158)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
at
org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
at
org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
at
org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
Caused by: javax.jms.JMSException: AMQ119014: Timed out after waiting 30,000 ms
for response when sending packet 43
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:397)
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:316)
at
org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.simpleCommit(ActiveMQSessionContext.java:328)
at
org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.commit(ClientSessionImpl.java:505)
at
org.apache.activemq.artemis.jms.client.ActiveMQSession.commit(ActiveMQSession.java:218)
at
org.apache.activemq.artemis.jms.example.ReplicatedTransactionFailoverExample.main(ReplicatedTransactionFailoverExample.java:86)
... 27 more
Caused by: ActiveMQConnectionTimedOutException[errorType=CONNECTION_TIMEDOUT
message=AMQ119014: Timed out after waiting 30,000 ms for response when sending
packet 43]
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
