Bug 5735 - testCoreThenRunCommand(frysk.hpd.TestCoreCommand) test fails
Summary: testCoreThenRunCommand(frysk.hpd.TestCoreCommand) test fails
Status: RESOLVED FIXED
Alias: None
Product: frysk
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
: P2 normal
Target Milestone: ---
Assignee: Phil Muldoon
URL:
Keywords:
Depends on:
Blocks: 2246
  Show dependency treegraph
 
Reported: 2008-02-06 09:16 UTC by Phil Muldoon
Modified: 2008-02-06 12:09 UTC (History)
0 users

See Also:
Host:
Target:
Build:
Last reconfirmed:


Attachments
Synchronize access to output buffer patch (711 bytes, patch)
2008-02-06 12:09 UTC, Phil Muldoon
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Phil Muldoon 2008-02-06 09:16:11 UTC
At the moment, I see this test failure:

Running testCoreThenRunCommand(frysk.hpd.TestCoreCommand) ...FAIL
  junit.framework.AssertionFailedError: sent: <run> expecting: <Attached to
process.*> got: <EOF>

Time: 0.884
There was 1 failure:
1)
testCoreThenRunCommand(frysk.hpd.TestCoreCommand)junit.framework.AssertionFailedError:
sent: <run> expecting: <Attached to process.*> got: <EOF>
   at frysk.hpd.HpdTestbed.expectPrompt(TestRunner)
   at frysk.hpd.HpdTestbed.sendCommandExpectPrompt(TestRunner)
   at frysk.hpd.TestCoreCommand.testCoreThenRunCommand(TestRunner)
   at frysk.junit.Runner.runCases(TestRunner)
   at frysk.junit.Runner.runTestCases(TestRunner)
   at TestRunner.main(TestRunner)

Replicating the test manually produces this result. This tests fails 100% so not
sure what is differing in the manual test, and the junit test. Tried with  same
results with setting break on _start.

(fhpd) load /home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello
Loaded executable file: 
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello

(fhpd) break main
breakpoint 0 deferred

(fhpd) run
Attached to process 10826
starting/running with this command:
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello 
Running process 10826
(fhpd) Breakpoint 0 main 0x4004e2

(fhpd) dump
Generating corefile 'core.10826' for process: 10826

(fhpd) quit

Quitting...

[pmuldoon@localhost frysk-core]$ ./frysk/bindir/fhpd core.10826
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello
Attached to core file: /home/pmuldoon/frysk_bin/frysk-core/core.10826

(fhpd) run

Attached to process 10858
starting/running with this command:
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello 

Running process 10858
(fhpd) Task 10858 is terminating from signal SIGSEGV(11)
Comment 1 Phil Muldoon 2008-02-06 09:34:54 UTC
I noticed that the test before it:

    public void testCoreExeCommand() {
	File exe = Config.getPkgLibFile("funit-hello");
	File core = CorefileFactory.constructCoreAtSignal(exe);
	e = new HpdTestbed();
	e.sendCommandExpectPrompt(("core " + core.getPath()
				   + " " + exe.getPath()),
				  "Attached to core file.*");
    }

Was essentially the same as the testCoreThenRunCommand, other than this
additional line in the testCoreThenRunCommand:

	e.sendCommandExpectPrompt("run",
				  "Attached to process.*");

On removing this the test files passes 100 out of 100 runs.

The whole of the test is:

    public void testCoreThenRunCommand() {
	File exe = Config.getPkgLibFile("funit-hello");
	File core = CorefileFactory.constructCoreAtSignal(exe);
	e = new HpdTestbed();
	e.sendCommandExpectPrompt(("core " + core.getPath()
				   + " " + exe.getPath()),
				  "Attached to core file.*");
	e.sendCommandExpectPrompt("run",
				  "Attached to process.*");
    }

Looking at the live load/run case in TestRunCommand.java, which is testing the
same functionality the test is differently constructed. Not the different expect
output and the thread.sleep(). I'll convert the corefile test to this one to see
if it passes with the different expect, and thread.sleep().

    public void testRunCommand() {
	e = new HpdTestbed();
	e.sendCommandExpectPrompt("load " +
Config.getPkgLibFile("funit-threads-looper").getPath(),
	"Loaded executable file.*");
	e.sendCommandExpectPrompt("run ",
		"Attached to process ([0-9]+).*Running process ([0-9]+).*");
	try { Thread.sleep(1000); } catch (Exception e) {}
	e.sendCommandExpectPrompt("focus","Target set.*\\[0\\.0\\]\t\t([0-9]+)" +
		"\t([0-9]+)\r\n" + "\\[0\\.1\\]\t\t([0-9]+)\t([0-9]+)\r\n");
	e.send("quit\n");
	e.expect("Quitting\\.\\.\\.");
	e.close();
    }

Comment 2 Phil Muldoon 2008-02-06 10:38:44 UTC
Altering the test has no effect. However I was investigating the cause of EOF.
Adding in a System.out.println into frysk.expunit.Child and the function:
expectMilliseconds:

	    System.out.print("Expect output: " + output);
	    if (eof) {
		fine.log(this, "match EOF");
		throw new EndOfFileException(matches, output);
	    }

I get the output:

Expect output: run 
Attached to process 11658
starting/running with this command:
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello 
Exception in thread "main" starting/running with this command:
/home/pmuldoon/frysk_bin/frysk-core/frysk/pkglibdir/funit-hello 
java.util.ConcurrentModificationException
   at java.util.LinkedList$LinkedListItr.checkMod(libgcj.so.8rh)
   at java.util.LinkedList$LinkedListItr.remove(libgcj.so.8rh)
   at frysk.hpd.CLI.flushMessages(fhpd)
   at frysk.hpd.CLI.execCommand(fhpd)
   at frysk.bindir.fhpd.main(fhpd)
FAIL
  junit.framework.AssertionFailedError: sent: <run > expecting: <Attached to
process ([0-9]+).*Running process ([0-9]+).*> got: <EOF>

Looking at flushmessages() in CLI.java:

    private void flushMessages() {
        for (Iterator iter = messages.iterator(); iter.hasNext();) {

I see the use of a fail-fast iterator. I suspect that in the SteppingEngine, the
injection of:

Task 10858 is terminating from signal SIGSEGV(11)

Is causing a concurrent modification exception and causing an EOF
Comment 3 Phil Muldoon 2008-02-06 10:51:01 UTC
Removing the injection of this message from frysk.step.SteppingEngine in
updateTerminating:

	    tse.setState(new StepTerminatedState(task, true));
	    if (signal != null)
		tse.setMessage(tse.getMessage()
			       + "Task " + task.getTid()
			       + " is terminating from signal " + signal);
	    else
		tse.setMessage(tse.getMessage()
			       + "Task " + task.getTid()
			       + " is exiting with status " + value);

	    steppingObserver.notifyNotBlocked(tse);

and the test passes. Looking at why, through the eventual change of execution:

Inside frysk/hpd/CLI.java, in the class SteppingObserver we see:

       public void update (Observable observable, Object arg) {
            TaskStepEngine tse = (TaskStepEngine) arg;
            if (!tse.isAlive()) {
		addMessage(tse.getMessage(), Message.TYPE_VERBOSE);
		tse.setMessage("");
		flushMessages();

If another message (say from the run command) alters the output of the message
buffer during flush, the concurrent exception error seems to happen.
Comment 4 Phil Muldoon 2008-02-06 12:09:08 UTC
Created attachment 2231 [details]
Synchronize access to output buffer patch
Comment 5 Phil Muldoon 2008-02-06 12:09:51 UTC
This patch fixes the bug