You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2017/07/05 22:06:00 UTC

[jira] [Commented] (QPID-7853) Message enqueued twice to the same queue leads to Broker failure

    [ https://issues.apache.org/jira/browse/QPID-7853?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16075508#comment-16075508 ] 

Keith Wall commented on QPID-7853:
----------------------------------

{{txn.enqueue(queues,message, new ServerTransaction.EnqueueAction()}} on line 502 of AbstractExchange.java on 6.1.x intends to pass {{baseQueues}} as actual parameter 1.  On master, the same code is in {{RoutingResult#send}}.

> Message enqueued twice to the same queue leads to Broker failure
> ----------------------------------------------------------------
>
>                 Key: QPID-7853
>                 URL: https://issues.apache.org/jira/browse/QPID-7853
>             Project: Qpid
>          Issue Type: Bug
>          Components: Java Broker
>    Affects Versions: qpid-java-6.0, qpid-java-6.1, qpid-java-6.1.4
>            Reporter: Keith Wall
>
> QPID-4307 added a defence against the same message being enqueued twice on a single queue, however a defect at {{org/apache/qpid/server/exchange/AbstractExchange.java:502}} means that it is still possible for this situation to arise on some paths.
> Reproduction:
> # Create queue with DLQ wired-up and max delivery count enforced.
> # Publish a single message to the queue.
> # Use management to copy the message from the queue to the DLQ
> # Transactionally consume the message and rollback until the message is dead-lettered..
> The following stack trace will appear and the Broker will shutdown.
> {noformat}
> /Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/bin/java -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:61800,suspend=y,server=n -DQPID_HOME=/Users/keith/src/qpid-broker-j/systests/target/qpid-broker/6.1.5-SNAPSHOT -DQPID_WORK=/Users/keith/src/qpid-broker-j/systests/target/qpid-broker/6.1.5-SNAPSHOT/work -DSSL_DIR=/Users/keith/src/qpid-broker-j/test-profiles/test_resources/ssl/ -Xmx4g -DXqpid.httpManagement.serveUncompressedDojo=true -DXqpid.broker.networkBufferSize=1046512 -Djavax.net.debugX=ssl -Dfile.encoding=UTF-8 -classpath "/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/jaccess.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/packager.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_131.jdk/Contents/Home/lib/tools.jar:/Users/keith/src/qpid-broker-j/broker/target/classes:/Users/keith/.m2/repository/org/dojotoolkit/dojo/1.10.3/dojo-1.10.3-distribution.zip:/Users/keith/src/qpid-broker-j/broker-core/target/classes:/Users/keith/.m2/repository/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.5.3/jackson-core-2.5.3.jar:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.5.3/jackson-databind-2.5.3.jar:/Users/keith/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.5.0/jackson-annotations-2.5.0.jar:/Users/keith/.m2/repository/org/apache/bcel/bcel/5.2/bcel-5.2.jar:/Users/keith/.m2/repository/com/google/guava/guava/18.0/guava-18.0.jar:/Users/keith/src/qpid-broker-j/common/target/classes:/Users/keith/.m2/repository/ch/qos/logback/logback-classic/1.2.2/logback-classic-1.2.2.jar:/Users/keith/.m2/repository/ch/qos/logback/logback-core/1.2.2/logback-core-1.2.2.jar:/Users/keith/src/qpid-broker-j/broker-plugins/logging-logback/target/classes:/Users/keith/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/Users/keith/src/qpid-broker-j/broker-plugins/access-control/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-0-8-protocol/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-0-10-protocol/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-1-0-protocol/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-msg-conv-0-8-to-0-10/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-msg-conv-0-8-to-1-0/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/amqp-msg-conv-0-10-to-1-0/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/derby-store/target/classes:/Users/keith/.m2/repository/org/apache/derby/derby/10.12.1.1/derby-10.12.1.1.jar:/Users/keith/src/qpid-broker-j/broker-plugins/jdbc-provider-bone/target/classes:/Users/keith/.m2/repository/com/jolbox/bonecp/0.7.1.RELEASE/bonecp-0.7.1.RELEASE.jar:/Users/keith/src/qpid-broker-j/broker-plugins/jdbc-store/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/management-http/target/classes:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-servlet_3.0_spec/1.0/geronimo-servlet_3.0_spec-1.0.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-server/8.1.17.v20150415/jetty-server-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-continuation/8.1.17.v20150415/jetty-continuation-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-http/8.1.17.v20150415/jetty-http-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-servlet/8.1.17.v20150415/jetty-servlet-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-security/8.1.17.v20150415/jetty-security-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-servlets/8.1.17.v20150415/jetty-servlets-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-util/8.1.17.v20150415/jetty-util-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/webjars/bower/dstore/1.1.1/dstore-1.1.1.jar:/Users/keith/.m2/repository/org/webjars/bower/dgrid/1.0.0/dgrid-1.0.0.jar:/Users/keith/src/qpid-broker-j/broker-plugins/memory-store/target/classes:/Users/keith/src/qpid-broker-j/broker-plugins/websocket/target/classes:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-websocket/8.1.17.v20150415/jetty-websocket-8.1.17.v20150415.jar:/Users/keith/.m2/repository/org/eclipse/jetty/jetty-io/8.1.17.v20150415/jetty-io-8.1.17.v20150415.jar:/Users/keith/src/qpid-broker-j/bdbstore/target/classes:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar" org.apache.qpid.server.Main
> Connected to the target VM, address: '127.0.0.1:61800', transport: 'socket'
> [Broker] BRK-1006 : Using configuration : /Users/keith/src/qpid-broker-j/systests/target/qpid-broker/6.1.5-SNAPSHOT/work/config.json
> [Broker] BRK-1001 : Startup : Version: 6.1.5-SNAPSHOT Build: 
> [Broker] BRK-1010 : Platform : JVM : Oracle Corporation version: 1.8.0_131-b11 OS : Mac OS X version: 10.12.5 arch: x86_64 cores: 8
> [Broker] BRK-1011 : Maximum Memory : Heap : 3,817,865,216 bytes Direct : 3,817,865,216 bytes
> [Broker] BRK-1017 : Process : PID : 25921
> [Broker] BRK-1002 : Starting : Listening on TCP port 5672
> [Broker] MNG-1001 : Web Management Startup
> [Broker] MNG-1002 : Starting : HTTP : Listening on TCP port 8080
> [Broker] MNG-1004 : Web Management Ready
> [Broker] BRK-1004 : Qpid Broker Ready
> ########################################################################
> #
> # Unhandled Exception org.apache.qpid.server.util.ServerScopedRuntimeException: org.apache.qpid.server.store.StoreException: Error writing enqueued message with id 8 for queue queue_DLQ with id 5daefc9b-12e5-48b6-840b-d67bb176367f to database in Thread IO-/127.0.0.1:61874
> #
> # Exiting
> #
> ########################################################################
> org.apache.qpid.server.util.ServerScopedRuntimeException: org.apache.qpid.server.store.StoreException: Error writing enqueued message with id 8 for queue queue_DLQ with id 5daefc9b-12e5-48b6-840b-d67bb176367f to database
> 	at org.apache.qpid.server.protocol.v0_10.AMQPConnection_0_10$3.run(AMQPConnection_0_10.java:166)
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at org.apache.qpid.server.protocol.v0_10.AMQPConnection_0_10.received(AMQPConnection_0_10.java:147)
> 	at org.apache.qpid.server.transport.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:143)
> 	at org.apache.qpid.server.transport.NonBlockingConnection.processAmqpData(NonBlockingConnection.java:624)
> 	at org.apache.qpid.server.transport.NonBlockingConnectionPlainDelegate.processData(NonBlockingConnectionPlainDelegate.java:58)
> 	at org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:512)
> 	at org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:285)
> 	at org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:130)
> 	at org.apache.qpid.server.transport.SelectorThread$ConnectionProcessor.processConnection(SelectorThread.java:563)
> 	at org.apache.qpid.server.transport.SelectorThread$SelectionTask.performSelect(SelectorThread.java:354)
> 	at org.apache.qpid.server.transport.SelectorThread$SelectionTask.run(SelectorThread.java:97)
> 	at org.apache.qpid.server.transport.SelectorThread.run(SelectorThread.java:521)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.qpid.server.store.StoreException: Error writing enqueued message with id 8 for queue queue_DLQ with id 5daefc9b-12e5-48b6-840b-d67bb176367f to database
> 	at org.apache.qpid.server.store.AbstractJDBCMessageStore.enqueueMessage(AbstractJDBCMessageStore.java:576)
> 	at org.apache.qpid.server.store.AbstractJDBCMessageStore.access$400(AbstractJDBCMessageStore.java:59)
> 	at org.apache.qpid.server.store.AbstractJDBCMessageStore$JDBCTransaction.enqueueMessage(AbstractJDBCMessageStore.java:1176)
> 	at org.apache.qpid.server.txn.LocalTransaction.enqueue(LocalTransaction.java:285)
> 	at org.apache.qpid.server.exchange.AbstractExchange.send(AbstractExchange.java:502)
> 	at org.apache.qpid.server.queue.QueueEntryImpl.routeToAlternate(QueueEntryImpl.java:604)
> 	at org.apache.qpid.server.protocol.v0_10.ConsumerTarget_0_10.sendToDLQOrDiscard(ConsumerTarget_0_10.java:479)
> 	at org.apache.qpid.server.protocol.v0_10.ConsumerTarget_0_10.release(ConsumerTarget_0_10.java:464)
> 	at org.apache.qpid.server.protocol.v0_10.ExplicitAcceptDispositionChangeListener.onRelease(ExplicitAcceptDispositionChangeListener.java:55)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSession$3.performAction(ServerSession.java:381)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSession.dispositionChange(ServerSession.java:458)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSession.release(ServerSession.java:377)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.messageRelease(ServerSessionDelegate.java:156)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.messageRelease(ServerSessionDelegate.java:88)
> 	at org.apache.qpid.transport.MessageRelease.dispatch(MessageRelease.java:88)
> 	at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:57)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:105)
> 	at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:88)
> 	at org.apache.qpid.transport.Method.delegate(Method.java:153)
> 	at org.apache.qpid.transport.Session.received(Session.java:582)
> 	at org.apache.qpid.transport.Connection.dispatch(Connection.java:448)
> 	at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:65)
> 	at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:41)
> 	at org.apache.qpid.transport.MethodDelegate.messageRelease(MethodDelegate.java:122)
> 	at org.apache.qpid.transport.MessageRelease.dispatch(MessageRelease.java:88)
> 	at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:55)
> 	at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:41)
> 	at org.apache.qpid.transport.Method.delegate(Method.java:153)
> 	at org.apache.qpid.transport.Connection.received(Connection.java:401)
> 	at org.apache.qpid.server.protocol.v0_10.ServerConnection.access$001(ServerConnection.java:67)
> 	at org.apache.qpid.server.protocol.v0_10.ServerConnection$2.run(ServerConnection.java:251)
> 	at org.apache.qpid.server.protocol.v0_10.ServerConnection$2.run(ServerConnection.java:247)
> 	at java.security.AccessController.doPrivileged(Native Method)
> 	at org.apache.qpid.server.protocol.v0_10.ServerConnection.received(ServerConnection.java:246)
> 	at org.apache.qpid.server.protocol.v0_10.ServerAssembler.emit(ServerAssembler.java:115)
> 	at org.apache.qpid.server.protocol.v0_10.ServerAssembler.assemble(ServerAssembler.java:204)
> 	at org.apache.qpid.server.protocol.v0_10.ServerAssembler.frame(ServerAssembler.java:144)
> 	at org.apache.qpid.server.protocol.v0_10.ServerAssembler.received(ServerAssembler.java:72)
> 	at org.apache.qpid.server.protocol.v0_10.ServerInputHandler.parse(ServerInputHandler.java:175)
> 	at org.apache.qpid.server.protocol.v0_10.ServerInputHandler.received(ServerInputHandler.java:82)
> 	at org.apache.qpid.server.protocol.v0_10.AMQPConnection_0_10$3.run(AMQPConnection_0_10.java:155)
> 	... 15 more
> Caused by: org.apache.derby.shared.common.error.DerbySQLIntegrityConstraintViolationException: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL170705224254580' defined on 'QPID_QUEUE_ENTRIES'.
> 	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown Source)
> 	at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown Source)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeLargeUpdate(Unknown Source)
> 	at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(Unknown Source)
> 	at org.apache.qpid.server.store.AbstractJDBCMessageStore.enqueueMessage(AbstractJDBCMessageStore.java:569)
> 	... 55 more
> Caused by: ERROR 23505: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL170705224254580' defined on 'QPID_QUEUE_ENTRIES'.
> 	at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> 	at org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.IndexChanger.insertAndCheckDups(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.IndexChanger.doInsert(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.IndexChanger.insert(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.IndexSetChanger.insert(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.RowChangerImpl.insertRow(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.InsertResultSet.normalInsertCore(Unknown Source)
> 	at org.apache.derby.impl.sql.execute.InsertResultSet.open(Unknown Source)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(Unknown Source)
> 	at org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
> 	... 60 more
> Disconnected from the target VM, address: '127.0.0.1:61800', transport: 'socket'
> Process finished with exit code 1
> {noformat}



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

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org