IOException and Message: Stream Closed

[Rupert Smith]

Occasionally my tests fail with IOException and Message: Stream Closed. Anybody else get this? I've added it as an issue on GitHub.

Rupert

[Rupert Smith]

On Tuesday, December 3, 2013 1:33:31 PM UTC, Rupert Smith wrote:

Occasionally my tests fail with IOException and Message: Stream Closed. Anybody else get this? I've added it as an issue on GitHub.

Thought I'd bump this one again and see if anyone has some ideas. I occasionally get test failures showing up as an NPE when calling step(), I think the stream closed is the underlying cause of the NPE.

In this particular case, I have another test that exhaustively tries all input combinations, and it passes, so I can be sure that it is not some error in my circuit that is occasionally showing up under randomized testing. This issue is annoying because I am doing a lot of randomized testing, and when I see an occasional test error my immediate thought is that the tests are showing up some part of the circuit that is only occasionally being hit by a test case, and is not working correctly.

What can be done to make the stream based IPC with the simulated DUT more reliable? I don't really understand why the stream is occasionally being closed, is the test process occasionally dying for some reason, or is it that the creating process is not waiting enough for it to get started up, or ...?

Rupert

[Rupert Smith]

On Tuesday, December 17, 2013 8:19:48 AM UTC, Rupert Smith wrote:

In this particular case, I have another test that exhaustively tries all input combinations, and it passes, so I can be sure that it is not some error in my circuit that is occasionally showing up under randomized testing. 

I should add, that was how I saw it fail just now. The test that it fails on is not always the same one. I just saw it fail on something that I am fairly certain is correct, which leads me back to suspecting the test system itself.

Rupert 

[Jonathan Bachrach]

how many iterations are you doing?  

is it failing at the beginning of a run or after many iterations?

unfortunately, the underlying stream based IPC in scala appears to have a leak that eventually runs out of memory.  perhaps there is a lower level java version of IPC that we could use that doesn’t have this problem?  i’m not completely sure that this is what’s happening your case.  i agree though that we need a more reliable mechanism.  one other possibility would be to write a scala based simulator.

--
You received this message because you are subscribed to the Google Groups "chisel-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to chisel-users...@googlegroups.com.
To post to this group, send email to chisel...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/chisel-users/3c063cb3-5d55-4869-98cf-412bc4b14eb4%40googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Rupert Smith]

On Wednesday, December 18, 2013 3:02:32 AM UTC, Jonathan Bachrach wrote:

how many iterations are you doing?   

is it failing at the beginning of a run or after many iterations?

Not sure, but I am putting code like this round the calls to step() to find out. All my calls to step() get made in one place in each test which implements a function that feeds in a certain input, and checks it generates an expected output:

var count = 0

  def checkInOut: (Int, Int, Int, Int, Int) => Unit =

  {

    (d0, d1, d2, d3, o) =>

    {

      val vars = new mutable.HashMap[Node, Node]()

      vars(c.io.bcd(0)) = UInt(d0)

      vars(c.io.bcd(1)) = UInt(d1)

      vars(c.io.bcd(2)) = UInt(d2)

      vars(c.io.bcd(3)) = UInt(d3)

      vars(c.io.out) = UInt(o)

      try {

      t.step(vars, isTrace = trace) should be(true)

      count = count + 1

      } catch  {

        case e:RuntimeException =>

          println("Failed on count: " + count)

        }

      }

    }

  }

 

unfortunately, the underlying stream based IPC in scala appears to have a leak that eventually runs out of memory.  perhaps there is a lower level java version of IPC that we could use that doesn’t have this problem?

Doesn't sound so good, I'm sure its not too hard to use streams from Java more directly.

 

 i’m not completely sure that this is what’s happening your case.  i agree though that we need a more reliable mechanism.  one other possibility would be to write a scala based simulator.

;-) Maybe a Java one would be a little quicker..? I imagine the tricky bit would be to implement the variable width bit arithmetic stuff, for example, you can't do 64 bit unsigned in a long in Java. I think in the C++ simulator this has been implemented with some clever library, I suppose there must already be an OS Java library that does similar stuff, perhaps it is more of a struggle to make that really efficient. 

The basics of a Java simulator should be a fairly easy port from the C++.

Actually, I think a Java one could be fast enough compared with the C++ one. I'm sure using stream based IPC with the C++ one will slow things down substantially for one thing.

[Rupert Smith]

On Wednesday, December 18, 2013 3:02:32 AM UTC, Jonathan Bachrach wrote:

how many iterations are you doing?  

is it failing at the beginning of a run or after many iterations?

I added the code to count the iterations before it fails. 39939 was the last one I got. Definitely not always at the start of a run.

The problem does not seem to be caused by a OutOfMemoryError, although if I keep on running the tests for long enough I will also run into that problem too.

[Rupert Smith]

On Wednesday, December 18, 2013 3:02:32 AM UTC, Jonathan Bachrach wrote:

unfortunately, the underlying stream based IPC in scala appears to have a leak that eventually runs out of memory.  perhaps there is a lower level java version of IPC that we could use that doesn’t have this problem?

Looking into this some more... It appears that Chisel is using the Java InputStream and OutputStream directly, not a Scala entity built on top of these. The exception is originating within the InputStream code. I'll paste the stack trace soon, but its on my laptop with no net access at the moment.

I found this Java bug report which is describing a similar issue:

http://bugs.sun.com/view_bug.do?bug_id=5101298

Although, in that case the exception should only appear when the child process is being destroyed. That suggests that perhaps the simulator process is occasionally being killed? From the JVM side that explanation is only possible if the call to endTest() were being made simultaneously while the test.step() is still running, or some other asynchronous call to p.destroy() is being made. This does not look like it is the case, as endTest() is only being called once all the tests have completed, and the whole begin test, run test, end test flow is happening in a single thread.

It would happen, and is expected, if the child process were to exit unexpectedly whilst the test is running? This is the most obvious explanation. I can try adding a break point when this exception happens in order to pause the JVM process, then take a look and see what the status of the simulator process is at that point in time.

Rupert

[Rupert Smith]

Also, the iteration count I posted before may not be correct. I was doing this:

val test = new ChunkerTest

for (i <- 1 to 1000) { run(test) }

Which runs a start/test/end cycle in each iteration, without resetting the count. I am now doing a run with:

for (i <- 1 to 1000) { run(test); test.count = 0 }

So will count the number of iterations to failure, starting from each new fork of the child process.

[Rupert Smith]

On Friday, January 10, 2014 8:30:21 AM UTC, Rupert Smith wrote:

Will count the number of iterations to failure, starting from each new fork of the child process.

Count is: 0

Every time. Suggests that the child process is occasionally failing to start, or dying immediately after being started. 

[Rupert Smith]

Here are the stack traces that I see most often. I can sometimes fail on a read and sometimes a write, suggesting it is sometimes getting beyond the first write, but I think as the pipe is buffered and asynchronous, this non-determinism is expected.

== Stream Closed on read:

All legal single inputs are accepted without error. *** FAILED ***

  java.io.IOException: Stream closed

  at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:162)

  at java.io.BufferedInputStream.fill(BufferedInputStream.java:206)

  at java.io.BufferedInputStream.read(BufferedInputStream.java:254)

  at Chisel.Tester.step(Tester.scala:93)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests.checkInOut(ChunkerTests.scala:68)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$3$$anonfun$apply$mcV$sp$2.apply$mcVI$sp(ChunkerTests.scala:123)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$3$$anonfun$apply$mcV$sp$2.apply(ChunkerTests.scala:123)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$3$$anonfun$apply$mcV$sp$2.apply(ChunkerTests.scala:123)

  at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:244)

  at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:244)

  ...

=== Stream closed on Write:

All illegal single inputs are recognized as errors. *** FAILED ***

  java.io.IOException: Stream closed

  at java.lang.ProcessBuilder$NullOutputStream.write(ProcessBuilder.java:434)

  at java.io.OutputStream.write(OutputStream.java:116)

  at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)

  at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)

  at Chisel.Tester.step(Tester.scala:90)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests.checkInOut(ChunkerTests.scala:68)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$2$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ChunkerTests.scala:116)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$2$$anonfun$apply$mcV$sp$1.apply(ChunkerTests.scala:116)

  at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests$$anonfun$2$$anonfun$apply$mcV$sp$1.apply(ChunkerTests.scala:116)

  at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:244)

  ...

=== 

Sometimes the tests slow down significantly, I think this is caused by the heap getting progressively smaller as memory leaks. 

Interesting a stack dump almost always gives me:

"ScalaTest-running-ChunkerTests" prio=10 tid=0x0000000000c5d000 nid=0xc0f waiting on condition [0x00007f3a62404000]

   java.lang.Thread.State: RUNNABLE

        at java.lang.Throwable.getStackTraceElement(Native Method)

        at java.lang.Throwable.getOurStackTrace(Throwable.java:826)

        - locked <0x00000000e4cd22d8> (a java.lang.Exception)

        at java.lang.Throwable.getStackTrace(Throwable.java:815)

        at java.lang.Thread.getStackTrace(Thread.java:1567)

        at Chisel.Node.<init>(Node.scala:138)

        at Chisel.Literal.<init>(Lit.scala:259)

        at Chisel.Literal$.apply(Lit.scala:217)

        at Chisel.Tester$$anonfun$step$2.apply(Tester.scala:117)

        at Chisel.Tester$$anonfun$step$2.apply(Tester.scala:104)

        at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:33)

        at scala.collection.mutable.ArrayOps$ofRef.foreach(ArrayOps.scala:108)

        at Chisel.Tester.step(Tester.scala:104)

        at com.thesett.numbers.chisel.impl.translator.rx.ChunkerTests.checkInOut(ChunkerTests.scala:68)

Suggesting this is quite an expensive call, and would probably feature highly if I did some profiling.

The stack trace is used to get a line number, for generating error reports when generating from the Chisel code. 

I think perhaps it is not needed when testing? and perhaps a version of Node could be written (Node-light), that is used in the test cases.

===

I'll add some logging statements to the simulator code, see if I can figure out at what point it dies.

Rupert