Closed japgolly closed 3 years ago
japgolly
commented
5 years ago FYI I think what's being serialised is a stack trace. I had a test that was failing via exception with a tiny exception message. Fixing that test has resulting in this issue here no longer occurring; therefore I think it's just a test exception stack trace for a really deep stack.
sjrd
commented
5 years ago Do you have a reproduction, by any chance?
gzm0
commented
5 years ago Note that the only serializer that calls writeUTF is the string serializer itself. So it seems we are actually dealing with such large string. A large stack trace will be serialized as a list (so it basically already breaks stuff down).
There is a possibility that a serializer dumps stuff into string and then tries to serialize that (which it shouldn't). A source map resolved stack trace would really help for this. IIUC you can get this by enabling ES6 and enabling source maps (@sjrd is this correct?).
sjrd
commented
5 years ago Just npm install source-map-support should be enough to get source-map-resolved stack traces. (Assuming the JS code runs in Node.js.)
sjrd
commented
5 years ago It might be necessary to do #3668 before we can fix this issue.
gzm0
commented
4 years ago @japgolly the ask for a source map resolved stack trace of this still stands. It would be really helpful for us to understand where this big string is coming from.
japgolly
commented
4 years ago Oh you're waiting on me?? Sorry, I didn't realise that. I can't provide a stack trace. I mean that's the whole problem right? I'm unable to get anymore information apart from that one line. I've got source-map-support installed globally -- makes no difference. I've also tried last test from SBT -- no additional information. I've love to see a stack trace too, not just to see where the exception is coming from in Scala.js, but also to see what part of my own code is causing it :)
I do have one new piece of information that I discovered only minutes ago. If I set parallelExecution := false in SBT, this problem goes away. I painstakingly spent hours tonight trying to isolate my tests to see which ones where causing the bug and couldn't replicate it at all. Then I realised that I had parallelExecution in testOnly := false in my SBT, so I decided to make it apply to test too and since then, the bug has gone away! That's all I know and all I've been able to derive.
sjrd
commented
4 years ago Even without repro, we could simply replace all uses of readUTF/writeUTF pairs by a custom encoding that supports all possible Strings.
gzm0
commented
4 years ago Even without repro, we could simply replace all uses of readUTF/writeUTF pairs by a custom encoding that supports all possible Strings.
I'm less convinced about this at this point. To me, it seems equally likely that, for example, an error recovery mechanism relies on the thing it tries to recover from. The message chaining this might cause (think wrapped exception with prepended message) might eventually trigger the exception.
Allowing larger strings to be sent would not fix that problem, but simply OOM at some point.
gzm0
commented
4 years ago (I realize I misread "could" as "would", so of course we could, but I'm not sure it will fix anything).
japgolly
commented
4 years ago Urgh, I'm running into this @#!$*&#@ problem again. This time I've managed to get a stack trace out! :tada:
[error] org.scalajs.testing.common.RPCCore$RPCException: java.io.UTFDataFormatException: encoded string too long: 65815 bytes
[error] at org.scalajs.testing.common.RPCCore.$anonfun$handleMessage$4(RPCCore.scala:78)
[error] at scala.Option.foreach(Option.scala:407)
[error] at org.scalajs.testing.common.RPCCore.$anonfun$handleMessage$1(RPCCore.scala:76)
[error] at org.scalajs.testing.common.RPCCore.$anonfun$handleMessage$1$adapted(RPCCore.scala:56)
[error] at org.scalajs.testing.common.Serializer$.withInputStream(Serializer.scala:60)
[error] at org.scalajs.testing.common.RPCCore.handleMessage(RPCCore.scala:56)
[error] at org.scalajs.testing.adapter.JSEnvRPC.$anonfun$run$1(JSEnvRPC.scala:25)
[error] at org.scalajs.testing.adapter.JSEnvRPC.$anonfun$run$1$adapted(JSEnvRPC.scala:25)
[error] at org.scalajs.jsenv.nodejs.ComRun$$anon$1.run(ComSupport.scala:74)
[error] Caused by: java.io.UTFDataFormatException: encoded string too long: 65815 bytes
[error] at java.io.DataOutputStream.writeUTF(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:364033)
[error] at org.scalajs.testing.common.Serializer$StringSerializer$.serialize(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:136832)
[error] at org.scalajs.testing.common.RPCCore.makeRPCMsg(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:16291)
[error] at <jscode>.{anonymous}()(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:16268)
[error] at scala.scalajs.runtime.AnonFunction1.apply(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:190147)
[error] at scala.util.Success.map(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:287210)
[error] at org.scalajs.testing.common.RPCCore.makeReply(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:16268)
[error] at <jscode>.{anonymous}()(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:16750)
[error] at scala.scalajs.runtime.AnonFunction1.apply(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:190147)
[error] at scala.concurrent.impl.Promise$Transformation.run(file:///tmp/shipreq.sbt/webapp-base-test/js/target/scala-2.13/webapp-base-test-test-fastopt.js:393398)Does that help?
gzm0
commented
4 years ago Thanks for following up. The stacktrace on the JS side is not resolved, so it's difficult for us to figure out what the frames are. Either a resolved stack trace (and the exact SJS version this is) or the exact -fastopt.js file could help us get more information.
gzm0
commented
4 years ago Also, which testing framework is this?
From what I can see here; it seems that the JS side is unable to serialize a reply of type string. The only reply of this type is the reply to the done method. It is called when testing is completed. The testing framework is supposed to reply with a summary message (like: "success: 10 failed: 3 total: 13"). So from this, it seems that the message the testing framework is trying to send is very big. Ideally, we figure out if this is intended; if yes, we can add support for larger messages. If no, we can fix the testing framework.
japgolly
commented
4 years ago Oh that makes a lot of sense. I'm using μtest which, once all tests have completed, prints this big summary of everything run, and any return values.
Also I can send you the fastopt.js file if that helps further. It's just that it's private so maybe I send to your email address or similar?
gzm0
commented
4 years ago Also I can send you the fastopt.js file if that helps further. It's just that it's private so maybe I send to your email address or similar?
There's no need. I think this quite clarifies the issue. Also, looking at uTest code, it seems indeed that it might assemble a large error message.
@lihaoyi could you confirm that this uTest behavior is as intended? If yes, we probably should indeed just support larger strings.
lihaoyi
commented
4 years ago yeah utest creates a test suite summary at the end IIRC, that lists all tests and their outputs. Could definitely be more than 65536 bytes
gzm0
commented
4 years ago For me, this is enough to classify this as a bug. @sjrd feel free to revert if you disagree.
The simplest fix would be to simply inline the implementation of writeUTF / readUTF and encode the length as an Int instead of a Short (or even a Long for super safety, but then managing the read buffer might be hard).
sjrd
commented
4 years ago A String cannot have a length greater than Int.MaxValue to begin with, so an Int would be the appropriate thing to use.
gzm0
commented
4 years ago Ah, but at least the Java implementation stores the number of encoded bytes, not the length of the string. So it can be longer. But of course we're free to also do that differently.
Just giving 0.6.28 a whirl. Now that underlying RPCCore exceptions are being reported (awesome) we might finally be able to track down the root causes of stuff that's been around for a while. Exciting! First cab off the rank:
java.io.DataOutputStream.writeUTF has a limit of 65535 because it first writes a two bit size (see) which means the RPC machinery might need some logic to split, send in batches and reconstruct large strings.
Or maybe it could just truncate messages for an easier, quicker, non-crashing solution if it's just std{out,err} piping?