console FINE java.util.logging.ConsoleHandler@13ccf8 24-Jul-06 10:30:48 AM frysk.junit.Runner$Results startTest FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) ---- startTest ---- Running testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) ...24-Jul-06 10:30:48 AM frysk.proc.TestLib setUp FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) <<<<<<<<<<<<<<<< start setUp 24-Jul-06 10:30:48 AM frysk.event.EventLoop FINE: {Thread[Thread-4,5,main]} new 24-Jul-06 10:30:48 AM frysk.proc.Host FINE: {frysk.proc.LinuxHost@1decc0,state=running} Host 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} PollWaitOnSigChld 24-Jul-06 10:30:48 AM frysk.proc.TestLib setUp FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) <<<<<<<<<<<<<<<< end setUp 24-Jul-06 10:30:48 AM frysk.proc.TestLib killDuringTearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) killDuringTearDown 7,576 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop start: startChild (Sig_USR1) 24-Jul-06 10:30:48 AM frysk.event.EventLoop runPolling FINE: {Thread[Thread-4,5,main]} runPolling long 24-Jul-06 10:30:48 AM frysk.event.TimerEvent FINE: {{frysk.event.EventLoop$2$Timeout@58bfa0,timeMillis=1153751453331,periodMillis=0},expiredfalse} new long 24-Jul-06 10:30:48 AM frysk.event.EventLoop$2$Timeout FINE: {{frysk.event.EventLoop$2$Timeout@58bfa0,timeMillis=1153751453331,periodMillis=0},expiredfalse} timeout 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld execute FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} execute 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid -1 errno 10 7576.7576: argv[0]=/notnfs/frysk-build/frysk-core/frysk/pkglibexecdir/funit-child 7576.7576: argv[1]=--wait=suspend 7576.7576: argv[2]=10 7576.7576: argv[3]=7570 7576.7576: starting 7576 7576.7576: new thread 7576.7576 7576.7576: notify 7570 with 10 (User defined signal 1) -- new thread 7576.7576 24-Jul-06 10:30:48 AM frysk.proc.TestLib$AckHandler$AckSignal execute FINE: {frysk.proc.TestLib$AckHandler$AckSignal@57d280,sig=Sig_USR1} execute (startChild (Sig_USR1)) 24-Jul-06 10:30:48 AM frysk.event.EventLoop remove FINE: {Thread[Thread-4,5,main]} remove SignalEvent 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop stop: startChild (Sig_USR1) 24-Jul-06 10:30:48 AM frysk.event.EventLoop runPending FINE: {Thread[Thread-4,5,main]} runPending 24-Jul-06 10:30:48 AM frysk.proc.HostState$1 handleRefresh FINE: {frysk.proc.LinuxHost@1decc0,state=running} handleRefresh 24-Jul-06 10:30:48 AM frysk.proc.Host getProc FINE: {frysk.proc.LinuxHost@1decc0,state=running} getProc ProcId 24-Jul-06 10:30:48 AM frysk.proc.ProcTasksObserver FINE: frysk.proc.ProcTasksObserver@5d6e40 new 24-Jul-06 10:30:48 AM frysk.event.EventLoop runPending FINE: {Thread[Thread-4,5,main]} runPending 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.Task requestAddClonedObserver FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=detached} requestAddClonedObserver 24-Jul-06 10:30:48 AM frysk.proc.Proc requestAddObserver FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=detached} requestAddObservation 24-Jul-06 10:30:48 AM frysk.proc.Task requestAddTerminatedObserver FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=detached} requestAddTerminatedObserver 24-Jul-06 10:30:48 AM frysk.proc.Proc requestAddObserver FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=detached} requestAddObservation 24-Jul-06 10:30:48 AM frysk.proc.ProcState$1 handleAddObservation FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=detached} handleAddObserver 24-Jul-06 10:30:48 AM frysk.proc.ProcState$Attaching initialState FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=detached} state 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.TaskState$1 handleAttach FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=detached} handleAttach 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendAttach FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=detached} sendAttach 24-Jul-06 10:30:48 AM frysk.proc.ProcState$Attaching$ToMainTask handleAddObservation FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=Attaching.ToMainTask} handleAddObservation 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop start: addClone (Sig_USR1,Sig_USR2) 24-Jul-06 10:30:48 AM frysk.event.EventLoop runPolling FINE: {Thread[Thread-4,5,main]} runPolling long 24-Jul-06 10:30:48 AM frysk.event.TimerEvent FINE: {{frysk.event.EventLoop$2$Timeout@58bfa0,timeMillis=1153751453361,periodMillis=0},expiredfalse} new long 24-Jul-06 10:30:48 AM frysk.event.EventLoop$2$Timeout FINE: {{frysk.event.EventLoop$2$Timeout@58bfa0,timeMillis=1153751453361,periodMillis=0},expiredfalse} timeout 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld execute FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} execute 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7576 status 0x137f 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 0 errno 0 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld$2 getTask FINE: {TaskId,7576} stopped 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.TaskState$2 handleStoppedEvent FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=attaching} handleStoppedEvent 24-Jul-06 10:30:48 AM frysk.proc.Proc performTaskAttachCompleted FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=Attaching.ToMainTask} performTaskAttachCompleted 24-Jul-06 10:30:48 AM frysk.proc.ProcState$Attaching$ToMainTask handleTaskAttachCompleted FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=Attaching.ToMainTask} handleTaskAttachCompleted 24-Jul-06 10:30:48 AM frysk.proc.ProcState$Attaching allAttached FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=Attaching.ToMainTask} allAttached 24-Jul-06 10:30:48 AM frysk.proc.TaskState$Attached handleAddObserver FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} handleAddObserver 24-Jul-06 10:30:48 AM frysk.proc.TestProcTasksObserver$ProcTasksTester existingTask FINE: ProcTasksTester.existingTask() task: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} 24-Jul-06 10:30:48 AM frysk.proc.TaskState$Attached handleAddObserver FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} handleAddObserver 24-Jul-06 10:30:48 AM frysk.proc.TaskState$Attached$WaitForContinueOrUnblock handleContinue FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} handleContinue 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendSetOptions FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} sendSetOptions 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendContinue FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=Attached.WaitForContinueOrUnblock} sendContinue 24-Jul-06 10:30:48 AM frysk.proc.Proc$ObservableXXX notify FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=Attaching.ToMainTask} notify -- all observers 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld execute FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} execute 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7576 status 0xa7f 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 0 errno 0 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld$2 getTask FINE: {TaskId,7576} stopped 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.TaskState$Running handleSignaledEvent FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} handleSignaledEvent 24-Jul-06 10:30:48 AM frysk.proc.Task notifySignaled FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} notifySignaled(int) 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendContinue FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} sendContinue 7576.7576: received signal 10 (User defined signal 1) 7576.7576: add clone 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld execute FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} execute 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7576 status 0x3057f 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 0 errno 0 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld$2 getTask FINE: {TaskId,7576} cloneEvent 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.Task FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} new -- create attached clone 24-Jul-06 10:30:48 AM frysk.proc.TaskState$Running handleClonedEvent FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} handleClonedEvent 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendContinue FINE: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} sendContinue 7576.7576: clone 0xb7f17ba0 @ 0 created (added) 7576.7576: notify 7570 with 12 (User defined signal 2) -- clone 0xb7f17ba0 @ 0 created (added) 24-Jul-06 10:30:48 AM frysk.proc.TestLib$AckHandler$AckSignal execute FINE: {frysk.proc.TestLib$AckHandler$AckSignal@5d9430,sig=Sig_USR2} execute (addClone (Sig_USR1,Sig_USR2)) 24-Jul-06 10:30:48 AM frysk.event.EventLoop remove FINE: {Thread[Thread-4,5,main]} remove SignalEvent 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop stop: addClone (Sig_USR1,Sig_USR2) 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop start: addClone (Sig_USR1,Sig_USR2) 24-Jul-06 10:30:48 AM frysk.event.EventLoop runPolling FINE: {Thread[Thread-4,5,main]} runPolling long 24-Jul-06 10:30:48 AM frysk.event.TimerEvent FINE: {{frysk.event.EventLoop$2$Timeout@5ce3e8,timeMillis=1153751453367,periodMillis=0},expiredfalse} new long 24-Jul-06 10:30:48 AM frysk.event.EventLoop$2$Timeout FINE: {{frysk.event.EventLoop$2$Timeout@5ce3e8,timeMillis=1153751453367,periodMillis=0},expiredfalse} timeout 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld execute FINE: {frysk.proc.LinuxHost$PollWaitOnSigChld@57d4b0,sig=Sig_CHLD} execute 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7577 status 0x137f 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 0 errno 0 24-Jul-06 10:30:48 AM frysk.proc.LinuxHost$PollWaitOnSigChld$2 getTask FINE: {TaskId,7577} stopped 24-Jul-06 10:30:48 AM frysk.proc.Host get FINE: {frysk.proc.LinuxHost@1decc0,state=running} get TaskId 24-Jul-06 10:30:48 AM frysk.proc.TaskState$StartClonedTask$11 handleStoppedEvent FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} handleStoppedEvent 24-Jul-06 10:30:48 AM frysk.proc.TaskState$StartClonedTask attemptContinue FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} attemptContinue 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendSetOptions FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} sendSetOptions 24-Jul-06 10:30:48 AM frysk.proc.TestProcTasksObserver$ProcTasksTester taskAdded FINE: ProcTasksTester.taskAdded() task: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} 24-Jul-06 10:30:48 AM frysk.proc.ProcTasksObserver updateClonedOffspring FINE: ProcTasksObserver.updateClonedOffspring() parent: {frysk.proc.LinuxTask@1e9ea0,pid=7576,tid=7576,state=running} offspring: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} 24-Jul-06 10:30:48 AM frysk.proc.Task requestAddClonedObserver FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} requestAddClonedObserver 24-Jul-06 10:30:48 AM frysk.proc.Proc requestAddObserver FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=running} requestAddObservation 24-Jul-06 10:30:48 AM frysk.proc.Task requestAddTerminatedObserver FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} requestAddTerminatedObserver 24-Jul-06 10:30:48 AM frysk.proc.Proc requestAddObserver FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=running} requestAddObservation 24-Jul-06 10:30:48 AM frysk.proc.Task requestUnblock FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.waitForStop} requestUnblock -- observer 24-Jul-06 10:30:48 AM frysk.proc.ProcState$3 handleAddObservation FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=running} handleAddObservation 24-Jul-06 10:30:48 AM frysk.proc.TaskState$StartClonedTask handleAddObserver FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.blockedOffspring} handleAddObserver 24-Jul-06 10:30:48 AM frysk.proc.ProcState$3 handleAddObservation FINE: {frysk.proc.LinuxProc@5cb730,pid=7576,state=running} handleAddObservation 24-Jul-06 10:30:48 AM frysk.proc.TaskState$StartClonedTask handleAddObserver FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.blockedOffspring} handleAddObserver 24-Jul-06 10:30:48 AM frysk.proc.TaskState$StartClonedTask$12 handleUnblock FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.blockedOffspring} handleUnblock 24-Jul-06 10:30:48 AM frysk.proc.LinuxTask sendContinue FINE: {frysk.proc.LinuxTask@1e9e40,pid=7576,tid=7577,state=StartClonedTask.blockedOffspring} sendContinue 7576.7577: new thread 7576.7577 7576.7577: notify 7570 with 10 (User defined signal 1) -- new thread 7576.7577 24-Jul-06 10:30:48 AM frysk.proc.TestLib$AckHandler$AckSignal execute FINE: {frysk.proc.TestLib$AckHandler$AckSignal@5d9450,sig=Sig_USR1} execute (addClone (Sig_USR1,Sig_USR2)) 24-Jul-06 10:30:48 AM frysk.event.EventLoop remove FINE: {Thread[Thread-4,5,main]} remove SignalEvent 24-Jul-06 10:30:48 AM frysk.proc.TestLib assertRunUntilStop FINE: class frysk.proc.TestLib assertRunUntilStop stop: addClone (Sig_USR1,Sig_USR2) 24-Jul-06 10:30:48 AM frysk.proc.TestLib tearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) >>>>>>>>>>>>>>>> start tearDown 24-Jul-06 10:30:48 AM frysk.proc.TestLib tearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) kill -KILL 7576 24-Jul-06 10:30:48 AM frysk.proc.TestLib tearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) kill -CONT 7576 24-Jul-06 10:30:48 AM frysk.proc.TestLib tearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) detach -KILL 7576 (failed) 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7576 status 0x6057f 24-Jul-06 10:30:48 AM frysk.proc.TestLib$10 detach FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) detach -KILL 7576 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid 7577 status 0x6057f 24-Jul-06 10:30:48 AM frysk.proc.TestLib$10 detach FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) detach -KILL 7577 24-Jul-06 10:30:48 AM frysk.sys.Wait log FINE: frysk.sys.Wait pid -1 errno 10 24-Jul-06 10:30:48 AM frysk.proc.TestLib tearDown FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) >>>>>>>>>>>>>>>> end tearDown 24-Jul-06 10:30:48 AM frysk.junit.Runner$Results endTest FINE: testDoCloneAckDaemon(frysk.proc.TestProcTasksObserver) ---- endTest ---- PASS Time: 5.077 There was 1 failure: 1) testDoCloneDetached(frysk.proc.TestProcTasksObserver)junit.framework.AssertionFailedError: event loop run explictly stopped (addClone (Sig_USR1,Sig_USR2)) at frysk.proc.TestLib.assertRunUntilStop(TestRunner) at frysk.proc.TestLib.assertRunUntilStop(TestRunner) at frysk.proc.TestLib$AckHandler.assertAwait(TestRunner) at frysk.proc.TestLib$AckHandler.await(TestRunner) at frysk.proc.TestLib$AckProcess.spawn(TestRunner) at frysk.proc.TestLib$AckProcess.addClone(TestRunner) at frysk.proc.TestProcTasksObserver.doClone(TestRunner) at frysk.proc.TestProcTasksObserver.testDoCloneDetached(TestRunner) at frysk.junit.Runner.(TestRunner) at TestRunner.main(TestRunner) FAILURES!!! Tests run: 2, Failures: 1, Errors: 0