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 2011/07/07 10:17:16 UTC
[jira] [Created] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Occasional test failures from ExternalACLTest under java.0.10
--------------------------------------------------------------
Key: QPID-3339
URL: https://issues.apache.org/jira/browse/QPID-3339
Project: Qpid
Issue Type: Bug
Reporter: Keith Wall
Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue.
{code}
$ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
{code}
The test output:
{code}
cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
------------- Standard Output ---------------
Testcase: testAccessAuthorizedSuccess took 2.447 sec
Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
Testcase: testAccessNoRightsFailure took 1.74 sec
Testcase: testClientDeleteQueueSuccess took 2.135 sec
Testcase: testServerDeleteQueueFailure took 2.015 sec
Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
Testcase: testClientCreateNamedQueueFailure took 1.779 sec
Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
Testcase: testClientPublishValidQueueSuccess took 1.769 sec
Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
Testcase: testServerCreateNamedQueueValid took 1.456 sec
Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
Caused an ERROR
Error closing connection: org.apache.qpid.AMQException: close() timed out
javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
Caused by: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
at org.apache.qpid.transport.Connection.close(Connection.java:601)
at org.apache.qpid.transport.Connection.close(Connection.java:568)
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
{code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Assigned] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall reassigned QPID-3339:
--------------------------------
Assignee: Robbie Gemmell (was: Keith Wall)
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Commented] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13072561#comment-13072561 ]
Keith Wall commented on QPID-3339:
----------------------------------
I can see the cause of this problem. The close timeout on the client is actually being provoked by an erroneous ACL DENY on the server.
The server begins processing the closed, which causes the server to try and delete the temporary queues created during the test. The queue delete causes a call to SecurityManager.authoriseDelete(), but sometimes, we are seeing an erroneous DENY, even although the ACL installed on the vhost allows the operation.
The cause of the problem is that subject attached to the running thread (thread local - SecurityManager#setThreadSubject()) is not being set when processing a closed(), therefore the outcome depends on whoever previously used the MINA acceptor thread. The test uses two users: client and server.
I think the correct solution is to set the call SecurityManager.setThreadSubject(scon.getAuthorizedSubject()) in ServerSessionDelegate#closed in the same way as is done in ServerSessionDelegate#command(). I'll submit a patch.
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Keith Wall
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Commented] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073261#comment-13073261 ]
Keith Wall commented on QPID-3339:
----------------------------------
Thanks Robbie. Yes I noticed the other sporadic failure too. Isn't this one QPID-2345?
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Closed] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall closed QPID-3339.
----------------------------
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Fix For: 0.13
>
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Commented] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Robbie Gemmell (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073396#comment-13073396 ]
Robbie Gemmell commented on QPID-3339:
--------------------------------------
It doesn't seem like QPID-2345 was raised due to it, and I dont think I've ever seen the 0-8/0-9 profiles fail ExternalACLTest due to it, but the described outcome/behaviour appears the same yes. I have linked the issues, but I'm as yet undecided on whether that means this one should be closed since there obviously are still "Occasional test failures from ExternalACLTest under java.0.10":)
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Resolved] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall resolved QPID-3339.
------------------------------
Resolution: Fixed
Fix Version/s: 0.13
Alex's resolution to QPID-3448 also resolves the remaining issue highlighted by this Jira.
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Fix For: 0.13
>
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Commented] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Robbie Gemmell (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073196#comment-13073196 ]
Robbie Gemmell commented on QPID-3339:
--------------------------------------
The patch looks good and seemed to resolve the issues previously being seen, so it is now applied. I am leaving the JIRA open due to another sporadic failure in ExternalACLTest though.
With those prior issues gone, repeseated execution of the tests occasionally gets me an error being thrown by one of the tests, *testClientConsumeFromNamedQueueFailure*. This seems to be because the test is expecting the ACL failure to result in a JMSException being thrown, and instead a different type is thrown. This seems to be due to a race causing the client side to reach a different part of its execution and throw a SessionException to indicate the problem instead. This produces a slightly different stacktrace than the successfull case which should allow analysis (logs shown below, onwards from the point of broker sending the exception to the client).
{noformat}
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,311 DEBUG [apache.qpid.transport.Connection] SEND: [conn:a96863] ch=0 id=0 ExecutionException(errorCode=UNAUTHORIZED_ACCESS, com
mandId=6, description=Cannot subscribe to '1': Permission denied)
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,311 DEBUG [transport.network.mina.MinaSender] sending data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [transport.network.mina.MinaSender] sent data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:a96863]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] RECV: [conn:1c1eceb] ch=0 ExecutionException(errorCode=UNAUTHORIZED_ACCESS, co
mmandId=6, description=Cannot subscribe to '1': Permission denied)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Session] ID: [0] 0
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] SEND: [conn:a96863] ch=0 SessionFlush(completed=true)
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [transport.network.mina.MinaSender] sending data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [transport.network.mina.MinaSender] sent data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:a96863]
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] SEND: [conn:a96863] ch=0 SessionRequestTimeout(timeout=0)
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [transport.network.mina.MinaSender] sending data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [transport.network.mina.MinaSender] sent data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:a96863]
main 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:1c1eceb]
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,312 DEBUG [apache.qpid.transport.Connection] SEND: [conn:a96863] ch=0 SessionDetach(name=[B@1742c56)
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,313 DEBUG [transport.network.mina.MinaSender] sending data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,313 DEBUG [transport.network.mina.MinaSender] sent data:
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,313 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:a96863]
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,313 DEBUG [apache.qpid.transport.Session] ssn:"a55a7219-8df6-4ec1-bf8c-89556d23c37f" processed([6, 6]) 5 5
MinaNetworkTransport(Acceptor)-15 2011-07-30 11:00:48,313 DEBUG [apache.qpid.transport.Session] {[0, 5]}
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,313 DEBUG [apache.qpid.client.AMQConnection] exceptionReceived done by:IoReceiver - localhost/127.0.0.1:15672
org.apache.qpid.AMQException: ch=0 id=0 ExecutionException(errorCode=UNAUTHORIZED_ACCESS, commandId=6, description=Cannot subscribe to '1': Permission denied) [error code 403: access
refused]
at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1058)
at org.apache.qpid.client.AMQSession_0_10.exception(AMQSession_0_10.java:921)
at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:160)
at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:32)
at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50)
at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:32)
at org.apache.qpid.transport.Method.delegate(Method.java:159)
at org.apache.qpid.transport.Session.received(Session.java:530)
at org.apache.qpid.transport.Connection.dispatch(Connection.java:411)
at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
at org.apache.qpid.transport.MethodDelegate.executionException(MethodDelegate.java:110)
at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:112)
at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
at org.apache.qpid.transport.Method.delegate(Method.java:159)
at org.apache.qpid.transport.Connection.received(Connection.java:376)
at org.apache.qpid.transport.Connection.received(Connection.java:66)
at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:95)
at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:196)
at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:129)
at org.apache.qpid.transport.network.Frame.delegate(Frame.java:133)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:100)
at org.apache.qpid.transport.network.Assembler.received(Assembler.java:42)
at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:187)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:103)
at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:42)
at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:140)
at java.lang.Thread.run(Thread.java:619)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,314 INFO [apache.qpid.client.AMQConnection] Closing AMQConnection due to :org.apache.qpid.AMQException: ch=0 id=0 Execution
Exception(errorCode=UNAUTHORIZED_ACCESS, commandId=6, description=Cannot subscribe to '1': Permission denied) [error code 403: access refused]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,314 DEBUG [apache.qpid.client.BasicMessageConsumer] Passed exception to synchronous queue for propagation to receive()
MinaNetworkTransport(Acceptor)-16 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] RECV: [conn:a96863] ch=0 MessageSetFlowMode(destination=1, flowMode=WINDOW)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.SessionDelegate] CLOSED: [ssn:"a55a7219-8df6-4ec1-bf8c-89556d23c37f"]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Session] ssn:"a55a7219-8df6-4ec1-bf8c-89556d23c37f" processed([0, 0]) -1 -1
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Session] {}
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] RECV: [conn:1c1eceb] ch=0 SessionFlush(completed=true)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] SEND: [conn:1c1eceb] ch=0 SessionCompleted(commands={[0, 0]})
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:1c1eceb]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] RECV: [conn:1c1eceb] ch=0 SessionRequestTimeout(timeout=0)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] SEND: [conn:1c1eceb] ch=0 SessionTimeout(timeout=0)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:1c1eceb]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] RECV: [conn:1c1eceb] ch=0 SessionDetach(name=[B@26efd3)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] SEND: [conn:1c1eceb] ch=0 SessionDetached(name=[B@26efd3, code=NORMAL)
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.Connection] FLUSH: [conn:1c1eceb]
IoReceiver - localhost/127.0.0.1:15672 2011-07-30 11:00:48,315 DEBUG [apache.qpid.transport.SessionDelegate] CLOSED: [ssn:"a55a7219-8df6-4ec1-bf8c-89556d23c37f"]
main 2011-07-30 11:00:48,316 ERROR [qpid.test.utils.QpidBrokerTestCase] exception
org.apache.qpid.transport.SessionException: ch=0 id=0 ExecutionException(errorCode=UNAUTHORIZED_ACCESS, commandId=6, description=Cannot subscribe to '1': Permission denied)
at org.apache.qpid.transport.Session.invoke(Session.java:625)
at org.apache.qpid.transport.Session.invoke(Session.java:561)
at org.apache.qpid.transport.SessionInvoker.messageFlow(SessionInvoker.java:132)
at org.apache.qpid.client.AMQSession_0_10.sendConsume(AMQSession_0_10.java:642)
at org.apache.qpid.client.AMQSession_0_10.sendConsume(AMQSession_0_10.java:82)
at org.apache.qpid.client.AMQSession.consumeFromQueue(AMQSession.java:2575)
at org.apache.qpid.client.AMQSession.registerConsumer(AMQSession.java:2892)
at org.apache.qpid.client.AMQSession.access$500(AMQSession.java:120)
at org.apache.qpid.client.AMQSession$4.execute(AMQSession.java:2034)
at org.apache.qpid.client.AMQSession$4.execute(AMQSession.java:2000)
at org.apache.qpid.client.AMQConnectionDelegate_0_10.executeRetrySupport(AMQConnectionDelegate_0_10.java:322)
at org.apache.qpid.client.AMQConnection.executeRetrySupport(AMQConnection.java:615)
at org.apache.qpid.client.failover.FailoverRetrySupport.execute(FailoverRetrySupport.java:102)
at org.apache.qpid.client.AMQSession.createConsumerImpl(AMQSession.java:1998)
at org.apache.qpid.client.AMQSession.createConsumer(AMQSession.java:971)
at org.apache.qpid.server.security.acl.ExternalACLTest.testClientConsumeFromNamedQueueFailure(ExternalACLTest.java:215)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at junit.framework.TestCase.runTest(TestCase.java:154)
at junit.framework.TestCase.runBare(TestCase.java:127)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:243)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:125)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:421)
at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:912)
at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:766)
{noformat}
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Robbie Gemmell
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Updated] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall updated QPID-3339:
-----------------------------
Component/s: Java Tests
Java Broker
Description:
Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
{code}
$ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
{code}
The test output:
{code}
cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
------------- Standard Output ---------------
Testcase: testAccessAuthorizedSuccess took 2.447 sec
Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
Testcase: testAccessNoRightsFailure took 1.74 sec
Testcase: testClientDeleteQueueSuccess took 2.135 sec
Testcase: testServerDeleteQueueFailure took 2.015 sec
Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
Testcase: testClientCreateNamedQueueFailure took 1.779 sec
Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
Testcase: testClientPublishValidQueueSuccess took 1.769 sec
Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
Testcase: testServerCreateNamedQueueValid took 1.456 sec
Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
Caused an ERROR
Error closing connection: org.apache.qpid.AMQException: close() timed out
javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
Caused by: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
at org.apache.qpid.transport.Connection.close(Connection.java:601)
at org.apache.qpid.transport.Connection.close(Connection.java:568)
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
{code}
was:
Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue.
{code}
$ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
[echo] Running ant for module : junit-toolkit
[junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
[junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
[junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
{code}
The test output:
{code}
cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
------------- Standard Output ---------------
Testcase: testAccessAuthorizedSuccess took 2.447 sec
Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
Testcase: testAccessNoRightsFailure took 1.74 sec
Testcase: testClientDeleteQueueSuccess took 2.135 sec
Testcase: testServerDeleteQueueFailure took 2.015 sec
Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
Testcase: testClientCreateNamedQueueFailure took 1.779 sec
Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
Testcase: testClientPublishValidQueueSuccess took 1.769 sec
Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
Testcase: testServerCreateNamedQueueValid took 1.456 sec
Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
Caused an ERROR
Error closing connection: org.apache.qpid.AMQException: close() timed out
javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
Caused by: org.apache.qpid.AMQException: close() timed out
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
at org.apache.qpid.transport.Connection.close(Connection.java:601)
at org.apache.qpid.transport.Connection.close(Connection.java:568)
at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
{code}
Affects Version/s: 0.12
0.11
0.10
Assignee: Keith Wall
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Keith Wall
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org
[jira] [Updated] (QPID-3339) Occasional test failures from
ExternalACLTest under java.0.10
Posted by "Keith Wall (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/QPID-3339?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall updated QPID-3339:
-----------------------------
Attachment: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
Hi Robbie
Could you review this patch please?
cheers Keith.
> Occasional test failures from ExternalACLTest under java.0.10
> --------------------------------------------------------------
>
> Key: QPID-3339
> URL: https://issues.apache.org/jira/browse/QPID-3339
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker, Java Tests
> Affects Versions: 0.10, 0.11, 0.12
> Reporter: Keith Wall
> Assignee: Keith Wall
> Attachments: 0001-QPID-3339-Occasional-test-failures-from-ExternalACLT.patch
>
>
> Running system test ExternalACLTest shows occasional test failures on the java.0.10 test profile. The stack trace always indicates a timeout during close (see below).
> Running the test in a loop from the shell, I see a failure rate of roughly one time in ten on my machine. This is a longstanding issue (at least five months)
> {code}
> $ while /bin/true; do ant -f build.xml test -Dprofile=java.0.10 -Dtest=ExternalACLTest | grep junit; done
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.928 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 39.897 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 40.134 sec
> [echo] Running ant for module : junit-toolkit
> [junit] Running org.apache.qpid.server.security.acl.ExternalACLTest
> [junit] Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.792 sec
> [junit] Test org.apache.qpid.server.security.acl.ExternalACLTest FAILED
> {code}
> The test output:
> {code}
> cat build/results/systests/TEST-org.apache.qpid.server.security.acl.ExternalACLTest.txt
> Testsuite: org.apache.qpid.server.security.acl.ExternalACLTest
> Tests run: 21, Failures: 0, Errors: 1, Time elapsed: 99.137 sec
> ------------- Standard Output ---------------
> Testcase: testAccessAuthorizedSuccess took 2.447 sec
> Testcase: testAccessVhostAuthorisedGuestSuccess took 2.168 sec
> Testcase: testAccessNoRightsFailure took 1.74 sec
> Testcase: testClientDeleteQueueSuccess took 2.135 sec
> Testcase: testServerDeleteQueueFailure took 2.015 sec
> Testcase: testClientConsumeFromTempQueueSuccess took 1.889 sec
> Testcase: testClientConsumeFromNamedQueueFailure took 1.859 sec
> Testcase: testClientCreateTemporaryQueueSuccess took 1.806 sec
> Testcase: testClientCreateNamedQueueFailure took 1.779 sec
> Testcase: testClientPublishUsingTransactionSuccess took 1.776 sec
> Testcase: testClientPublishValidQueueSuccess took 1.769 sec
> Testcase: testClientPublishInvalidQueueSuccess took 1.771 sec
> Testcase: testServerConsumeFromNamedQueueValid took 1.838 sec
> Testcase: testServerConsumeFromNamedQueueInvalid took 1.856 sec
> Testcase: testServerConsumeFromTemporaryQueue took 1.42 sec
> Testcase: testServerCreateNamedQueueValid took 1.456 sec
> Testcase: testServerCreateNamedQueueInvalid took 1.777 sec
> Testcase: testServerCreateTemporaryQueueInvalid took 1.786 sec
> Testcase: testServerCreateAutoDeleteQueueInvalid took 1.787 sec
> Testcase: testServerPublishUsingTransactionSuccess took 62.239 sec
> Caused an ERROR
> Error closing connection: org.apache.qpid.AMQException: close() timed out
> javax.jms.JMSException: Error closing connection: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:913)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:864)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:848)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:839)
> at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:834)
> at org.apache.qpid.server.security.acl.ExternalACLTest.testServerPublishUsingTransactionSuccess(ExternalACLTest.java:586)
> at org.apache.qpid.test.utils.QpidBrokerTestCase.runBare(QpidBrokerTestCase.java:234)
> at org.apache.qpid.test.utils.QpidTestCase.run(QpidTestCase.java:120)
> Caused by: org.apache.qpid.AMQException: close() timed out
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:238)
> at org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:897)
> Caused by: org.apache.qpid.transport.ConnectionException: close() timed out
> at org.apache.qpid.transport.Connection.close(Connection.java:601)
> at org.apache.qpid.transport.Connection.close(Connection.java:568)
> at org.apache.qpid.client.AMQConnectionDelegate_0_10.closeConnection(AMQConnectionDelegate_0_10.java:234)
> Testcase: testServerPublishInvalidQueueSuccess took 1.795 sec
> {code}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:dev-subscribe@qpid.apache.org