Bug 849719
Summary: | IBM perfharness fails to "Connection refused" | ||
---|---|---|---|
Product: | Red Hat Enterprise MRG | Reporter: | ppecka <ppecka> |
Component: | qpid-java | Assignee: | Rajith Attapattu <rattapat+nobody> |
Status: | CLOSED CURRENTRELEASE | QA Contact: | ppecka <ppecka> |
Severity: | high | Docs Contact: | |
Priority: | high | ||
Version: | 2.2 | CC: | iboverma, jross, rattapat+nobody |
Target Milestone: | 2.3 | ||
Target Release: | --- | ||
Hardware: | Unspecified | ||
OS: | Unspecified | ||
Whiteboard: | |||
Fixed In Version: | Doc Type: | Bug Fix | |
Doc Text: | Story Points: | --- | |
Clone Of: | Environment: | ||
Last Closed: | 2012-09-24 15:52:11 UTC | Type: | Bug |
Regression: | --- | Mount Type: | --- |
Documentation: | --- | CRM: | |
Verified Versions: | Category: | --- | |
oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
Cloudforms Team: | --- | Target Upstream Version: | |
Embargoed: |
Comment 1
Rajith Attapattu
2012-08-21 01:56:20 UTC
The above turned out to be a non issue. Verified after testing multiple times. The real issue is as follows. ----------------------------- While the client waits on a commit, the connection is lost. And subsequent connections are also unsucessful. This could be due to, 1. The broker closing the connection and refusing subsequent connections. The probability is low, as the broker is still around and there are no logs indicating the broker closing the connection. 2. Intermittent network issues. Probability is high for several reasons, 1. Difficult to reproduce suggesting it could be an env issue 2. The connection is lost and subsquent connections lost with broker having no trace of it. 3. The test framework closing the connection due to a timeout. This is unlikely as the codepaths show in the exception is only triggered when the connection is lost - not when it's closed normally. (In reply to comment #3) > > 2. Intermittent network issues. Probability is high for several reasons, > 1. Difficult to reproduce suggesting it could be an env issue > 2. The connection is lost and subsquent connections lost with broker > having no trace of it. we found similar looking issue when two consequent JMS client testcases from our internal QE testsuite was refused/broke connection. Test is running against localhost broker in beaker environment. following testcases are passing as ususal. Again effort to see such exception is ~ "very hard" 12:50:09] -TEST-CASE:V.MRG.M.0015.82;TEST-CASE-DESC:Bug 730977: java client fails to resolve target when assert is used in the address ... (JAVA)------------ [12:50:09] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "amq.direct;{ assert:always, node: { type:topic }, link: { } }" [12:50:14] RESPONSE: {} IoSender - localhost/127.0.0.1:5672 2012-08-21 12:50:14,939 ERROR [transport.network.io.IoSender] error in write thread java.net.SocketException: Broken pipe at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) at java.net.SocketOutputStream.write(SocketOutputStream.java:153) at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313) at java.lang.Thread.run(Thread.java:679) Exception in thread "main" org.apache.qpid.AMQConnectionFailureException: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:444) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:215) at org.apache.qpid.example.OptionParser.createConnection(OptionParser.java:281) at org.apache.qpid.example.Drain.<init>(Drain.java:66) at org.apache.qpid.example.Drain.main(Drain.java:104) Caused by: org.apache.qpid.AMQException: Cannot connect to broker: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:239) at org.apache.qpid.client.AMQConnection.makeBrokerConnection(AMQConnection.java:588) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:367) ... 4 more Caused by: org.apache.qpid.transport.ConnectionException: connect() aborted at org.apache.qpid.transport.Connection.connect(Connection.java:282) at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:219) ... 6 more [12:50:14] [ FAIL ]: ret_code: 1 (not expected) here is better snippet out of testlogs regarding my comment 4 [12:50:04] -TEST-CASE:V.MRG.M.0015.81;TEST-CASE-DESC:Bug 731096: Wrong assertion result using python client (JAVA)------------ [12:50:04] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q731096;{ create: always, node: { }, link: { } }" [12:50:05] RESPONSE: {} [12:50:05] [ PASS ]: ret_code: 0 (expected) [12:50:05] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q731096;{ assert:always, node: { durable:True }, link: { } }" [12:50:06] RESPONSE: {} Exception in thread "main" javax.jms.JMSException: Error registering consumer: org.apache.qpid.AMQException: The name 'Q731096' supplied in the address doesn't resolve to an exchange or a queue at org.apache.qpid.client.AMQSession$4.execute(AMQSession.java:2056) at org.apache.qpid.client.AMQSession$4.execute(AMQSession.java:2008) at org.apache.qpid.client.AMQConnectionDelegate_0_10.executeRetrySupport(AMQConnectionDelegate_0_10.java:369) at org.apache.qpid.client.AMQConnection.executeRetrySupport(AMQConnection.java:593) at org.apache.qpid.client.failover.FailoverRetrySupport.execute(FailoverRetrySupport.java:102) at org.apache.qpid.client.AMQSession.createConsumerImpl(AMQSession.java:2006) at org.apache.qpid.client.AMQSession.createConsumer(AMQSession.java:980) at org.apache.qpid.example.Drain.<init>(Drain.java:70) at org.apache.qpid.example.Drain.main(Drain.java:104) Caused by: org.apache.qpid.AMQException: The name 'Q731096' supplied in the address doesn't resolve to an exchange or a queue at org.apache.qpid.client.AMQSession_0_10.handleAddressBasedDestination(AMQSession_0_10.java:1257) at org.apache.qpid.client.AMQSession.registerConsumer(AMQSession.java:2925) at org.apache.qpid.client.AMQSession.access$500(AMQSession.java:102) at org.apache.qpid.client.AMQSession$4.execute(AMQSession.java:2033) ... 8 more [12:50:06] [ PASS ]: ret_code: 1 (expected) [12:50:06] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q731096;{ assert:always, node: { x-declare:{exclusive:True} }, link: { } }" [12:50:08] RESPONSE: {} IoSender - localhost/127.0.0.1:5672 2012-08-21 12:50:08,858 ERROR [transport.network.io.IoSender] error in write thread java.net.SocketException: Broken pipe at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) at java.net.SocketOutputStream.write(SocketOutputStream.java:153) at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313) at java.lang.Thread.run(Thread.java:679) Exception in thread "main" org.apache.qpid.AMQConnectionFailureException: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:444) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:215) at org.apache.qpid.example.OptionParser.createConnection(OptionParser.java:281) at org.apache.qpid.example.Drain.<init>(Drain.java:66) at org.apache.qpid.example.Drain.main(Drain.java:104) Caused by: org.apache.qpid.AMQException: Cannot connect to broker: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:239) at org.apache.qpid.client.AMQConnection.makeBrokerConnection(AMQConnection.java:588) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:367) ... 4 more Caused by: org.apache.qpid.transport.ConnectionException: connect() aborted at org.apache.qpid.transport.Connection.connect(Connection.java:282) at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:219) ... 6 more [12:50:08] [ PASS ]: ret_code: 1 (expected) [12:50:08] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q731096;{ delete:always, node: { }, link: { } }" [12:50:09] RESPONSE: {} [12:50:09] [ PASS ]: ret_code: 0 (expected) [12:50:09] -TEST-CASE:V.MRG.M.0015.82;TEST-CASE-DESC:Bug 730977: java client fails to resolve target when assert is used in the address ... (JAVA)------------ [12:50:09] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "amq.direct;{ assert:always, node: { type:topic }, link: { } }" [12:50:14] RESPONSE: {} IoSender - localhost/127.0.0.1:5672 2012-08-21 12:50:14,939 ERROR [transport.network.io.IoSender] error in write thread java.net.SocketException: Broken pipe at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) at java.net.SocketOutputStream.write(SocketOutputStream.java:153) at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313) at java.lang.Thread.run(Thread.java:679) Exception in thread "main" org.apache.qpid.AMQConnectionFailureException: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:444) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:215) at org.apache.qpid.example.OptionParser.createConnection(OptionParser.java:281) at org.apache.qpid.example.Drain.<init>(Drain.java:66) at org.apache.qpid.example.Drain.main(Drain.java:104) Caused by: org.apache.qpid.AMQException: Cannot connect to broker: connect() aborted [error code 200: reply success] at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:239) at org.apache.qpid.client.AMQConnection.makeBrokerConnection(AMQConnection.java:588) at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:367) ... 4 more Caused by: org.apache.qpid.transport.ConnectionException: connect() aborted at org.apache.qpid.transport.Connection.connect(Connection.java:282) at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:219) ... 6 more [12:50:14] [ FAIL ]: ret_code: 1 (not expected) [12:50:14] -TEST-CASE:V.MRG.M.0015.83;TEST-CASE-DESC:Bug 731043: timeout waiting for sync (JAVA)------------ [12:50:15] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Spout "ex;{ create:sender,delete:sender, node: { type:topic,x-declare:{type:direct} }, link: { } }" (content="") [12:51:15] RESPONSE: {content=} ------------- Msg ------------- Body: JMS Correlation ID: null JMS timestamp: 1345567815519 JMS expiration: 0 JMS priority: 4 JMS delivery mode: 2 JMS reply to: null JMS Redelivered: false JMS Destination: 'ex'/None; { 'create': 'sender', 'delete': 'sender', 'link': {}, 'node': { 'type': 'topic', 'x-declare': { 'type': 'direct' } } } JMS Type: null JMS MessageID: ID:c558475b-4bfa-3509-b17d-4b952db7433f JMS Content-Type: text/plain AMQ message number: -1 Properties: qpid.subject = ------------------------------- main 2012-08-21 12:51:15,526 ERROR [apache.qpid.client.AMQConnection] Throwable Received but no listener set: org.apache.qpid.AMQException: timed out waiting for sync: complete = 2, point = 4 [error code 541: internal error] Exception in thread "main" javax.jms.JMSException: Error closing session: org.apache.qpid.AMQException: timed out waiting for sync: complete = 2, point = 4 [error code 541: internal error]IoReceiver - localhost/127.0.0.1:5672 2012-08-21 12:51:15,527 ERROR [apache.qpid.client.AMQConnection] Throwable Received but no listener set: org.apache.qpid.AMQException: ch=0 id=1 ExecutionException(errorCode=NOT_FOUND, commandId=4, classCode=8, commandCode=2, fieldIndex=0, description=not-found: Delete failed. No such queue: (qpid/broker/Broker.cpp:940), errorInfo={}) [error code 404: not found] at org.apache.qpid.client.AMQSession.close(AMQSession.java:761) at org.apache.qpid.client.AMQSession.close(AMQSession.java:723) at org.apache.qpid.client.AMQSession.close(AMQSession.java:569) at org.apache.qpid.example.Spout.<init>(Spout.java:103) at org.apache.qpid.example.Spout.main(Spout.java:146) Caused by: org.apache.qpid.AMQException: timed out waiting for sync: complete = 2, point = 4 [error code 541: internal error] at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1051) at org.apache.qpid.client.AMQSession_0_10.sendClose(AMQSession_0_10.java:403) at org.apache.qpid.client.AMQSession.close(AMQSession.java:755) ... 4 more [12:51:15] [ FAIL ]: ret_code: 1 (not expected) [12:51:15] -TEST-CASE:V.MRG.M.0015.84;TEST-CASE-DESC:Bug 730981: Unable to create binding while sending messages on default exchange ... (JAVA)------------ [12:51:15] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q730981;{ create:always, node: { }, link: { } }" [12:51:16] RESPONSE: {} [12:51:16] [ PASS ]: ret_code: 0 (expected) [12:51:16] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Spout "amq.direct;{ create:always, node: { x-bindings:[{queue:'Q730981',key:'key'}] }, link: { } }" (content="") [12:51:16] RESPONSE: {content=} ------------- Msg ------------- Body: JMS Correlation ID: null JMS timestamp: 1345567876945 JMS expiration: 0 JMS priority: 4 JMS delivery mode: 2 JMS reply to: null JMS Redelivered: false JMS Destination: 'amq.direct'/None; { 'create': 'always', 'link': {}, 'node': { 'x-bindings': [ { 'key': 'key', 'queue': 'Q730981' } ] } } JMS Type: null JMS MessageID: ID:dc9afc5f-8288-3f07-867b-9aa09f170634 JMS Content-Type: text/plain AMQ message number: -1 Properties: qpid.subject = ------------------------------- [12:51:16] [ PASS ]: ret_code: 0 (expected) [12:51:16] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q730981;{ delete:always, node: { }, link: { } }" [12:51:17] RESPONSE: {} [12:51:17] [ PASS ]: ret_code: 0 (expected) [12:51:17] -TEST-CASE:V.MRG.M.0015.85;TEST-CASE-DESC:Bug 731408: Using assert in address string leads to binding creation + different ... (JAVA)------------ [12:51:17] COMMAND: java -cp /mnt/tests/distribution/MRG/Messaging/qpid_ptest_clients_interoperability/examples/java:/usr/share/java/qpid-deps/log4j-slf4j.jar:/usr/share/java/qpid-deps/qpid-deps-0.18.jar:/usr/share/java/log4j.jar:/usr/share/java/qpid-client-0.18-sources.jar:/usr/share/java/qpid-client-0.18.jar:/usr/share/java/qpid-common-0.18-sources.jar:/usr/share/java/qpid-common-0.18.jar: -Dlog4j.configuration=example.log4j org.apache.qpid.example.Drain "Q731408;{ create:always, node: { }, link: { } }" [12:51:18] RESPONSE: {} [12:51:18] [ PASS ]: ret_code: 0 (expected) Petr, Are you able to retest this case with the changes we made for the connection issue? Regards, Rajith (In reply to comment #6) > Petr, > > Are you able to retest this case with the changes we made for the connection > issue? > > Regards, > > Rajith sure, i'll leave test running over weekend we heave been re-running test which triggered issue for many times, exception disappeared after we raised max-negotiate-time. it was more likely related to issue BZ851574 which has been already resolved This issue appears to have been addressed by changes made for bug 851574. -> CLOSED CURRENTRELEASE. |