Main /
Notes about notifyAll() in DEDirectorWe started getting IllegalMonitorStateException when calling DEDirector.fireAt(). Below are details. Replication from the command linecd ptolemy/actor/lib/jjs/modules/socket/test/junit make Messages like the following will appear: ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Dec 24, 2015 12:08:00 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2505 ms. Memory: 549888K Free: 198591K (36%) reloadAllAccessors: .Message3 Note that the problem does not occur when running Replicating In EclipseStart a new Java Application configuration
Edit DEDirector and change: _eventQueue.notifyAll(); } return result; try { _eventQueue.notifyAll(); } catch (IllegalMonitorStateException ex) { throw ex; } } return result; and set a breakpoint at the Below is the stack trace that I get: junit jjs socket [Java Application] org.junit.runner.JUnitCore at localhost:54100 Thread [main] (Running) Daemon Thread [vertx-blocked-thread-checker] (Running) Thread [vert.x-eventloop-thread-1] (Suspended (breakpoint at line 685 in DEDirector)) owns: DECQEventQueue (id=337) owns: NetSocketImpl (id=338) DEDirector.fireAt(Actor, Time, int) line: 685 DEDirector.fireAt(Actor, Time) line: 562 DEDirector.fireAtCurrentTime(Actor) line: 711 JavaScript.invokeCallback(Runnable) line: 1264 SocketHelper(HelperBase)._issueResponse(Runnable) line: 177 SocketHelper.access$1(SocketHelper, Runnable) line: 1 SocketHelper$SocketWrapper.lambda$4(Void) line: 491 1050898636.handle(Object) line: not available NetSocketImpl(ConnectionBase).handleClosed() line: 175 NetSocketImpl.handleClosed() line: 287 169939665.run() line: not available EventLoopContext(ContextImpl).lambda$wrapTask$61(boolean, ContextTask, Handler) line: 333 1440459972.run() line: not available EventLoopContext(ContextImpl).executeFromIO(ContextTask) line: 225 VertxNetHandler(VertxHandler<C>).channelInactive(ChannelHandlerContext) line: 99 DefaultChannelHandlerContext(AbstractChannelHandlerContext).invokeChannelInactive() line: 208 DefaultChannelPipeline$HeadContext(AbstractChannelHandlerContext).fireChannelInactive() line: 194 DefaultChannelPipeline.fireChannelInactive() line: 828 AbstractChannel$AbstractUnsafe$7.run() line: 621 NioEventLoop(SingleThreadEventExecutor).runAllTasks(long) line: 358 NioEventLoop.run() line: 357 SingleThreadEventExecutor$2.run() line: 112 VertxThread(Thread).run() line: 745 Thread [vert.x-eventloop-thread-0] (Running) Thread [vert.x-eventloop-thread-3] (Running) Thread [vert.x-eventloop-thread-2] (Running) Daemon Thread [threadDeathWatcher-2-1] (Running) Thread [vert.x-eventloop-thread-9] (Running) Thread [vert.x-eventloop-thread-8] (Running) Thread [vert.x-eventloop-thread-10] (Running) Thread [vert.x-eventloop-thread-11] (Running) Thread [Thread-16] (Running) Thread [vert.x-eventloop-thread-15] (Running) /Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/bin/java (Dec 24, 2015, 10:02:40 AM) FindBugs notifyAll() WarningFindBugs does complain about notifyAll() at that location: DEDirector.java:682, MWN_MISMATCHED_NOTIFY, Priority: Normal MWN: Mismatched notify() in ptolemy.domains.de.kernel.DEDirector.fireAt(Actor, Time, int) This method calls Object.notify() or Object.notifyAll() without obviously holding a lock on the object. Calling notify() or notifyAll() without a lock held will result in an IllegalMonitorStateException being thrown. The call to synchronized (_eventQueue) { if (!_delegateFireAt) { // If we have not made a request to the executive director, // then we can modify time here. If we have, then we can't, // but if the time of that request is now in the past, // we will throw an exception with an attempt to post // an event in the past. if (result.compareTo(getModelTime()) < 0) { // NOTE: There is no assurance in a multithreaded situation // that time will not advance prior to the posting of // this returned time on the local event queue, so // an exception can still occur reporting an attempt // to post an event in the past. result = getModelTime(); } } if (result.compareTo(getModelTime()) == 0 && index <= _microstep && !_isInitializing) { // NOTE: Incrementing the microstep here is wrong if we are in initialize(). index = _microstep + 1; if (index == Integer.MAX_VALUE) { throw new IllegalActionException( this, actor, "Microstep has hit the maximum while scheduling a firing of " + actor.getFullName() + ". Perhaps the model has a stuttering Zeno Condition?"); } } _enqueueEvent(actor, result, index); // Findbugs: Multithreaded correctness, // [M M MWN] Mismatched notify() [MWN_MISMATCHED_NOTIFY] // This method calls Object.notify() or Object.notifyAll() // without obviously holding a lock on the object. // Calling notify() or notifyAll() without a lock // held will result in an IllegalMonitorStateException // being thrown. // Actually, this seems to be Find Bugs error since the // statement is within a synchronized (_eventQueue) block. ------> _eventQueue.notifyAll(); } return result; } The call to synchronized (_eventQueue) { _eventQueue.put(newEvent); } So, Coverity Scan WarningsSummary: Checking the Coverity Scan Warnings at http://scan.coverity.com shows two other warnings for DEDirector, but they are probably not relevant. Details: There are two warnings One warning is: CID 1250909 (#1 of 1): Unguarded write (GUARDED_BY_VIOLATION)63. missing_lock: Accessing _exceedStopTime without holding lock DEDirector._eventQueue. lsewhere, "ptolemy.domains.de.kernel.DEDirector._exceedStopTime" is accessed with DEDirector._eventQueue held 3 out of 4 times. The offending line in DEDirector._getNextActorToFire() is marked below: // Exceeding stop time means the current time is strictly // bigger than the model stop time. if (currentTime.compareTo(getModelStopTime()) > 0) { if (_debugging) { _debug("Current time has passed the stop time."); } ------> _exceedStopTime = true; return null; } _getNextActorToFire() is called at the top of fire(), so this is probably not the issue. Another Coverity Scan warning is: CID 1250851 (#1 of 1): Check of thread-shared field evades lock acquisition (LOCK_EVASION)9. thread1_overwrites_value_in_field: Thread1 sets _microstep to a new value. Now the two threads have an inconsistent view of _microstep and updates to fields correlated with _microstep may be lost. The above also occurs in _getNextActorToFire(), so it is probably also not the issue here. JUnitOddly, running make in but running make in in Summary: The problem occurs with the second junit run of Message2.xml Message3.xml, Socket3.xml Details below. JUnit Failure #1A typical failure is ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Dec 24, 2015 12:08:00 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2505 ms. Memory: 549888K Free: 198591K (36%) reloadAllAccessors: .Message3 JUnit Failure #2.----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Socket3.xml Client: Discarding because socket is not open: a 3441 ms. Memory: 821760K Free: 470260K (57%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Socket3.xml Dec 23, 2015 12:44:49 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Discarding because socket is not open: a 3500 ms. Memory: 821760K Free: 267336K (33%) reloadAllAccessors: .Socket3 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/SocketByte.xml Client: Sending data: -1,0,1,128,256 Client3: Sending data: 127 2751 ms. Memory: 827904K Free: 258013K (31%) JUnit Failure #3----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message2.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5 2580 ms. Memory: 411136K Free: 370859K (90%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message2.xml Dec 23, 2015 12:51:26 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Sending data: 5,1,2,3 Client: Sending data: 4,5 2573 ms. Memory: 413184K Free: 362581K (88%) reloadAllAccessors: .Message2 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml 2588 ms. Memory: 481280K Free: 309069K (64%) java.lang.RuntimeException: Execution failed at ptolemy.moml.MoMLSimpleApplication$UnloadThread.run(MoMLSimpleApplication.java:367) Caused by: ptolemy.kernel.util.IllegalActionException: Exceptions occurred during wrapup: ptolemy.kernel.util.IllegalActionException: The fire() method of this actor was never called. Usually, this is an error indicating that \ starvation is occurring. in .Message3.Test JUnit Failure #4----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message2.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5 2561 ms. Memory: 408064K Free: 339288K (83%) reloadAllAccessors: .Message2 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2532 ms. Memory: 476160K Free: 272887K (57%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Dec 23, 2015 12:58:05 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2542 ms. Memory: 478720K Free: 313006K (65%) reloadAllAccessors: .Message3 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message4.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3,2,1 2523 ms. Memory: 546816K Free: 307313K (56%) JUnit Failure #5.----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message2.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5 2600 ms. Memory: 410624K Free: 362291K (88%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message2.xml Dec 23, 2015 1:01:51 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Sending data: 5,1,2,3 Client: Sending data: 4,5 2558 ms. Memory: 412160K Free: 338015K (82%) reloadAllAccessors: .Message2 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2510 ms. Memory: 471040K Free: 255755K (54%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Message3.xml Client: Sending data: 5,1,2,3 Client: Sending data: 4,5,3,1,2,3 2535 ms. Memory: 477696K Free: 284158K (59%) reloadAllAccessors: .Message3 Later, in the same run: .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Socket3.xml Client: Discarding because socket is not open: a 3444 ms. Memory: 794624K Free: 364136K (46%) ----------------- testing again /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/Socket3.xml Dec 23, 2015 1:02:18 PM io.vertx.core.impl.ContextImpl SEVERE: Unhandled exception java.lang.IllegalMonitorStateException at java.lang.Object.notifyAll(Native Method) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:682) at ptolemy.domains.de.kernel.DEDirector.fireAt(DEDirector.java:562) at ptolemy.domains.de.kernel.DEDirector.fireAtCurrentTime(DEDirector.java:707) at ptolemy.actor.lib.jjs.JavaScript.invokeCallback(JavaScript.java:1264) at ptolemy.actor.lib.jjs.HelperBase._issueResponse(HelperBase.java:177) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper.access$1900(SocketHelper.java:95) at ptolemy.actor.lib.jjs.modules.socket.SocketHelper$SocketWrapper.lambda$null$12(SocketHelper.java:491) at io.vertx.core.net.impl.ConnectionBase.handleClosed(ConnectionBase.java:175) at io.vertx.core.net.impl.NetSocketImpl.handleClosed(NetSocketImpl.java:287) at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:333) at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:225) at io.vertx.core.net.impl.VertxHandler.channelInactive(VertxHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:208) at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:194) at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:828) at io.netty.channel.AbstractChannel$AbstractUnsafe$7.run(AbstractChannel.java:621) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) Client: Discarding because socket is not open: a 3586 ms. Memory: 799232K Free: 597774K (75%) reloadAllAccessors: .Socket3 .----------------- testing /Users/cxh/ptII/ptolemy/actor/lib/jjs/modules/socket/test/auto/SocketByte.xml Client: Sending data: -1,0,1,128,256 Client3: Sending data: 127 2801 ms. Memory: 876032K Free: 619395K (71%) Possible SolutionEdward wrote: This is a really weird one... The only reason I can think of for the findBugs warning is that findBugs may believe that the _eventQueue field could change between when the synchronization lock is acquired and when notifyAll is called. This would only occur if a second execution of the model actually overlaps in time with the first... I guess this is theoretically possible, and may in fact be happening in the test mechanism that is triggering the bug. One possible fix might be in preinitialize. Instead of: public void preinitialize() throws IllegalActionException { _isInitializing = true; // Initialize an event queue. _eventQueue = new DECQEventQueue( ((IntToken) minBinCount.getToken()).intValue(), ((IntToken) binCountFactor.getToken()).intValue(), ((BooleanToken) isCQAdaptive.getToken()).booleanValue()); we could do: public void preinitialize() throws IllegalActionException { if (_eventQueue != null) { // This execution may be overlapped with the previous. synchronized(_eventQueue) { _isInitializing = true; // Initialize an event queue. _eventQueue = new DECQEventQueue( ((IntToken) minBinCount.getToken()).intValue(), ((IntToken) binCountFactor.getToken()).intValue(), ((BooleanToken) isCQAdaptive.getToken()).booleanValue()); } } else { _isInitializing = true; // Initialize an event queue. _eventQueue = new DECQEventQueue( ((IntToken) minBinCount.getToken()).intValue(), ((IntToken) binCountFactor.getToken()).intValue(), ((BooleanToken) isCQAdaptive.getToken()).booleanValue()); } Another alternative would be to build a mechanism for the second execution to wait until the first has completely wrapped up. That could be tricky, however, as there may be external threads attempting to queue events even after wrapup is called. Possible Solution ContinuedUnfortunately, that means that we are changing the value of the lock while holding the lock. FindBugs warns: DEDirector.java:1309, ML_SYNC_ON_FIELD_TO_GUARD_CHANGING_THAT_FIELD, Priority: High ML: Synchronization on DEDirector._eventQueue in futile attempt to guard it This method synchronizes on a field in what appears to be an attempt to guard against simultaneous updates to that field. But guarding a field gets a lock on the referenced object, not on the field. This may not provide the mutual exclusion you need, and other threads might be obtaining locks on the referenced objects (for other purposes). An example of this pattern would be: private Long myNtfSeqNbrCounter = new Long(0); private Long getNotificationSequenceNumber() { Long result = null; synchronized(myNtfSeqNbrCounter) { result = new Long(myNtfSeqNbrCounter.longValue() + 1); myNtfSeqNbrCounter = new Long(result.longValue()); } return result; } Even worse, PtidesDirector.preinitialize() looks like: public class PtidesDirector extends DEDirector implements Decorator { ... public void preinitialize() throws IllegalActionException { super.preinitialize(); _eventQueue = new PtidesListEventQueue(); PtidesDirector should be using synchronized() in many places... I see these options:
The problem with #3 is that _eventQueue() is declared as a DEEventQueue, but we instantiate a DECQEventQueue(). So we can't just create DECQEventQueue.initialize(int minBinCount, int binCountFactor, boolean isAdaptive) and invoke it in DEDirector.preinitialize() because _eventQueue is declared as a DEEventQueue(). In DEDirector.preinitialize(), we could do an instanceof check, but this seems wrong, especially because PtidesDirector.preinitialize() is setting _eventQueue to a new PtidesListEventQueue after the call to DEDirector.preinitialize() So, I'm thinking that we need to add a lock, which I've done, which solves the FindBugs warnings and passes the test in ptolemy/actor/lib/jjs/modules/socket/test/junit See Also
|