You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@qpid.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2012/06/13 05:11:07 UTC

Build failed in Jenkins: Qpid-Python-Java-Test #247

See <https://builds.apache.org/job/Qpid-Python-Java-Test/247/changes>

Changes:

[aconway] QPID-3603: HA bug fixes around transition to ready status

- Simplify QueueGuard::firstSafe calculation.
- Fix error in setting initial queues - was not checking if replicated.
- Send ready status to backups. Tests hang, deadlock in opened()->RemoteBackup on primary?
- Fix deadlock in QueueGuard.
- Don't start guards inside ConnectionObserver::opened.

[aconway] QPID-3603: Lock in Queue::getPosition.

Needed to ensure serialization of position changes with setObservers for ha plugin.

[aconway] QPID-3603: HA bug fixes around ha::QueueGuard

- Remove nested calls between QueueGuard::dequeued and ReplicatingSubscription
- ReplicatingSubscription can't start ahead of QueueGuard::getReadyPosition()
- Fix QueueGuard firstSafe calcultatoin
- Replace DequeueRemover with DequeueScanner in ReplicatingSubscription
- Removed bad assertions in ReplicatingSubscription and QueueGuard

[aconway] QPID-3603: Improvements to HA log messages, clarify primary/backp role.

[aconway] QPID-3603: Guard should not complete messages from the internal event queue.

ReplicatingSubscription::acknowledge was calling Guard::complete for messages on the
internal event queue as well as the replicated queue. Corrected to only complete
messages from the replicated queue.

[aconway] QPID-3603: Move calls to ConfigurationObserver outside of locks.

[aconway] QPID-3603: Introduced RemoteBackup to track backup status.

The primary creates RemoteBackup object for each connected or expected
backup. On first being promoted, the new primary has a RemoteBackup
for each of the known backups at the time of the failure.

The RemoteBackup manages queue guards for its backup and
tracks it's readiness.

[aconway] QPID-3603: Separate QueueGuard from ReplicatingSubscription.

QueueGuard: implements QueueObserver to delay completion of new messages.
ReplicatingSubscription: Implements subscription, sends messages & events to backup.

These were previously combined as one. QueueGuard is now separated out
so that it can be created before the ReplicatingSubscription, in
anticipation of an expected backup connecting. This is needed for 2 reasons:
- new queues must be guarded until they are backuped up.
- after a failover, all queues must be guarded until backups are ready.

[rgodfrey] QPID-4062 : [Java Tests] add misssing file from previous checkin

[tross] QPID-4060 - qpid-stat - Improve the help text to clarify use of the different display modes

[tross] QPID-4059 - qpid-printevents refactored to use the lighter-weight management library

[chug] QPID-3902 Log categories
Change "IO" to "Network", "AMQP" to "Protocol", and add "Client" category.

[aconway] NO-JIRA: Fix parsing of C++ URLs in qpid.messaging.util to handle IPv6 addresses.

[rgodfrey] QPID-4062 : [Java Tests] Java system tests sometimes fail due to JMX port already initialised (Applied patch from Philip Harvey

[aconway] NO-JIRA: Fix failing unit_test, updated for changes in log format.

The test had not been updated to account for changes to log format, adding
[Category] to front of messages.

[kgiusti] QPID-4046: set intrusive ptr to zero instead of calling reset() - compatible with older releases of boost

[rgodfrey] QPID-4055 : [Java Broker] update to latest version of BDB library

------------------------------------------
[...truncated 7782 lines...]

"FelixStartLevel" daemon prio=10 tid=0xabec1400 nid=0x3684 in Object.wait() [0xabdfe000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0xb72aba28> (a java.util.ArrayList)
	at java.lang.Object.wait(Object.java:485)
	at org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:242)
	- locked <0xb72aba28> (a java.util.ArrayList)
	at java.lang.Thread.run(Thread.java:662)

"FelixDispatchQueue" prio=10 tid=0xabef3800 nid=0x3683 in Object.wait() [0xac094000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0xb72abab0> (a java.util.ArrayList)
	at java.lang.Object.wait(Object.java:485)
	at org.apache.felix.framework.util.EventDispatcher.run(EventDispatcher.java:917)
	- locked <0xb72abab0> (a java.util.ArrayList)
	at org.apache.felix.framework.util.EventDispatcher.access$000(EventDispatcher.java:54)
	at org.apache.felix.framework.util.EventDispatcher$1.run(EventDispatcher.java:106)
	at java.lang.Thread.run(Thread.java:662)

"Low Memory Detector" daemon prio=10 tid=0xac635400 nid=0x3681 runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0xac633400 nid=0x3680 waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0xac631c00 nid=0x367f waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0xac630000 nid=0x367e runnable [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (Concurrent GC)" daemon prio=10 tid=0xac62ec00 nid=0x367d waiting on condition [0x00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0xac621000 nid=0x367c in Object.wait() [0xac5ad000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0xb72aab98> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
	- locked <0xb72aab98> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0xac61f800 nid=0x367b in Object.wait() [0xac5fe000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0xb72abba8> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
	- locked <0xb72abba8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0xac61bc00 nid=0x367a runnable 

"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x0930bc00 nid=0x366f runnable 

"Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x0930d400 nid=0x3670 runnable 

"Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x0930ec00 nid=0x3671 runnable 

"Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x09310000 nid=0x3672 runnable 

"Gang worker#4 (Parallel GC Threads)" prio=10 tid=0x09311800 nid=0x3673 runnable 

"Gang worker#5 (Parallel GC Threads)" prio=10 tid=0x09312c00 nid=0x3674 runnable 

"Gang worker#6 (Parallel GC Threads)" prio=10 tid=0xf3601800 nid=0x3675 runnable 

"Gang worker#7 (Parallel GC Threads)" prio=10 tid=0xf3602c00 nid=0x3676 runnable 

"Concurrent Mark-Sweep GC Thread" prio=10 tid=0xaed91000 nid=0x3679 runnable 
"Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0xaed0e000 nid=0x3677 runnable 

"Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0xaed0f800 nid=0x3678 runnable 

"VM Periodic Task Thread" prio=10 tid=0xac637400 nid=0x3682 waiting on condition 

JNI global references: 1117


Found one Java-level deadlock:
=============================
"IoReceiver - /0:0:0:0:0:0:0:1:59475":
  waiting to lock monitor 0x09599d74 (object 0xb738e6a8, a org.apache.qpid.server.txn.DtxRegistry),
  which is held by "IoReceiver - /0:0:0:0:0:0:0:1:59466"
"IoReceiver - /0:0:0:0:0:0:0:1:59466":
  waiting to lock monitor 0x0944a328 (object 0xb7473878, a org.apache.qpid.server.txn.DtxBranch),
  which is held by "IoReceiver - /0:0:0:0:0:0:0:1:59465"
"IoReceiver - /0:0:0:0:0:0:0:1:59465":
  waiting to lock monitor 0x09599d74 (object 0xb738e6a8, a org.apache.qpid.server.txn.DtxRegistry),
  which is held by "IoReceiver - /0:0:0:0:0:0:0:1:59466"

Java stack information for the threads listed above:
===================================================
"IoReceiver - /0:0:0:0:0:0:0:1:59475":
	at org.apache.qpid.server.txn.DtxRegistry.getBranch(DtxRegistry.java:100)
	- waiting to lock <0xb738e6a8> (a org.apache.qpid.server.txn.DtxRegistry)
	at org.apache.qpid.server.txn.DistributedTransaction.start(DistributedTransaction.java:163)
	at org.apache.qpid.server.transport.ServerSession.startDtx(ServerSession.java:495)
	at org.apache.qpid.server.transport.ServerSessionDelegate.dtxStart(ServerSessionDelegate.java:459)
	at org.apache.qpid.server.transport.ServerSessionDelegate.dtxStart(ServerSessionDelegate.java:74)
	at org.apache.qpid.transport.DtxStart.dispatch(DtxStart.java:89)
	at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55)
	at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:98)
	at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:74)
	at org.apache.qpid.transport.Method.delegate(Method.java:159)
	at org.apache.qpid.transport.Session.received(Session.java:584)
	at org.apache.qpid.transport.Connection.dispatch(Connection.java:421)
	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.dtxStart(MethodDelegate.java:161)
	at org.apache.qpid.transport.DtxStart.dispatch(DtxStart.java:89)
	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.server.transport.ServerConnection.received(ServerConnection.java:225)
	at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:59)
	at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97)
	at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:198)
	at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131)
	at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:44)
	at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:189)
	at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:105)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:109)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:42)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:118)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:37)
	at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:152)
	at java.lang.Thread.run(Thread.java:662)
"IoReceiver - /0:0:0:0:0:0:0:1:59466":
	at org.apache.qpid.server.txn.DtxBranch.isAssociated(DtxBranch.java:141)
	- waiting to lock <0xb7473878> (a org.apache.qpid.server.txn.DtxBranch)
	at org.apache.qpid.server.txn.DtxRegistry.endAssociations(DtxRegistry.java:315)
	- locked <0xb738e6a8> (a org.apache.qpid.server.txn.DtxRegistry)
	at org.apache.qpid.server.transport.ServerSession.onClose(ServerSession.java:380)
	at org.apache.qpid.server.transport.ServerSessionDelegate.closed(ServerSessionDelegate.java:1573)
	at org.apache.qpid.transport.Session.closed(Session.java:1096)
	- locked <0xb73eb240> (a java.lang.Object)
	at org.apache.qpid.transport.ConnectionDelegate.sessionDetached(ConnectionDelegate.java:105)
	at org.apache.qpid.transport.ConnectionDelegate.sessionDetached(ConnectionDelegate.java:40)
	at org.apache.qpid.transport.SessionDetached.dispatch(SessionDetached.java:91)
	at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:49)
	at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:40)
	at org.apache.qpid.transport.Method.delegate(Method.java:163)
	at org.apache.qpid.transport.Connection.received(Connection.java:376)
	at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:225)
	at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:59)
	at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97)
	at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:183)
	at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131)
	at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:44)
	at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:189)
	at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:105)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:109)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:42)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:118)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:37)
	at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:152)
	at java.lang.Thread.run(Thread.java:662)
"IoReceiver - /0:0:0:0:0:0:0:1:59465":
	at org.apache.qpid.server.txn.DtxRegistry.unregisterBranch(DtxRegistry.java:116)
	- waiting to lock <0xb738e6a8> (a org.apache.qpid.server.txn.DtxRegistry)
	at org.apache.qpid.server.txn.DtxRegistry.rollback(DtxRegistry.java:228)
	- locked <0xb7473878> (a org.apache.qpid.server.txn.DtxBranch)
	at org.apache.qpid.server.transport.ServerSession.rollbackDtx(ServerSession.java:543)
	at org.apache.qpid.server.transport.ServerSessionDelegate.dtxRollback(ServerSessionDelegate.java:640)
	at org.apache.qpid.server.transport.ServerSessionDelegate.dtxRollback(ServerSessionDelegate.java:74)
	at org.apache.qpid.transport.DtxRollback.dispatch(DtxRollback.java:87)
	at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55)
	at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:98)
	at org.apache.qpid.server.transport.ServerSessionDelegate.command(ServerSessionDelegate.java:74)
	at org.apache.qpid.transport.Method.delegate(Method.java:159)
	at org.apache.qpid.transport.Session.received(Session.java:584)
	at org.apache.qpid.transport.Connection.dispatch(Connection.java:421)
	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.dtxRollback(MethodDelegate.java:182)
	at org.apache.qpid.transport.DtxRollback.dispatch(DtxRollback.java:87)
	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.server.transport.ServerConnection.received(ServerConnection.java:225)
	at org.apache.qpid.server.transport.ServerConnection.received(ServerConnection.java:59)
	at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97)
	at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:198)
	at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131)
	at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102)
	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:44)
	at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:189)
	at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:105)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:109)
	at org.apache.qpid.server.protocol.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:42)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:118)
	at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:37)
	at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:152)
	at java.lang.Thread.run(Thread.java:662)

Found 1 deadlock.

+ kill -9 13924
+ pwd
<https://builds.apache.org/job/Qpid-Python-Java-Test/ws/>
+ cd trunk/qpid/python
+ ulimit -n
40000
+ ulimit -n 1024
+ ulimit -n
1024
+ ant -file qpid-python-test-ant.xml -Dqpid.executable=../java/build/bin/qpid-server -Dpython.test.ignore=-I../java/test-profiles/python_tests/Java010PythonExcludes '-Dpython.test.modules=-mqpid_tests.broker_0_10 -m qmf.console' -Dqpid.port=25672 '-Dqpid.executable.args=-p 25672 -m 25000' test
Buildfile: qpid-python-test-ant.xml

clean:

init:
    [mkdir] Created dir: <https://builds.apache.org/job/Qpid-Python-Java-Test/ws/trunk/qpid/python/build/results>
    [mkdir] Created dir: <https://builds.apache.org/job/Qpid-Python-Java-Test/ws/trunk/qpid/python/build/work>

ensure-port-free:

start-broker:
     [echo] Starting Qpid with ../java/build/bin/qpid-server -p 25672 -m 25000

run-tests:
     [echo] Running test-suite
     [exec] Result: 1

stop-broker:
     [echo] Stopping Qpid 17339

kill-broker:

report:

BUILD FAILED
<https://builds.apache.org/job/Qpid-Python-Java-Test/ws/trunk/qpid/python/qpid-python-test-ant.xml>:113: Test(s) failed

Total time: 3 minutes 21 seconds
Build step 'Execute shell' marked build as failure
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Recording test results

Jenkins build is back to normal : Qpid-Python-Java-Test #248

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Qpid-Python-Java-Test/248/changes>