NPE starting VS Code debugger

nirvdrum commented 2 years ago

Describe GraalVM and your environment :

GraalVM version or commit id if built from source: 23.0.0-dev (3abb64734edf5c2f12a557ac4d5674cf27758a75)
CE or EE: CE
JDK version: JDK11
OS and OS Version: macOS 12.6
Architecture: Apple M1

The output of java -Xinternalversion:

OpenJDK 64-Bit Server VM (11.0.17+5-jvmci-22.3-b05) for bsd-aarch64 JRE (11.0.17+5-jvmci-22.3-b05), built on Sep  5 2022 11:40:30 by "graal1" with clang Apple LLVM 12.0.0 (clang-1200.0.32.29)

Have you verified this issue still happens when using the latest snapshot?

Yes.

Describe the issue

I've seen an NPE in the debugger terminal just by starting a TruffleRuby debug session in VS Code. The debugger continues to work, so this isn't a blocker. But, the exception does print a bunch of text to the terminal that I wouldn't expect to see.

Code snippet or code repository that reproduces the issue

This is happening with a private project. If the stack trace is insufficient, I'm happy to run an instrumented build for you.

Steps to reproduce the issue Please include both build steps as well as run steps

Set up a TruffleRuby launch configuration in VS Code with the "console": "integratedTerminal" option
Launch the debugger
Look at the debugger terminal

Expected behavior

I expected the debugger to launch successfully and not print out exception details to the terminal output.

Additional context Add any other context about the problem here. Specially important are stack traces or log output. Feel free to link to gists or to screenshots if necessary.

Unfortunately, the exception report is truncated. Due to #4906, I'm unable to find a full stack trace. If there's a way to collect it, please let me know. I'm not terribly well-versed in VS Code's internals.

Details

``` ava.lang.Exception: Output operation write(B[II) failed for com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream@3403e2ac. at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.handleException(DispatchOutputStream.java:274) at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.writeMulti(DispatchOutputStream.java:216) at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream.write(DispatchOutputStream.java:130) at java.base/sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:233) at java.base/sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:312) at java.base/sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:316) at java.base/sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:153) at java.base/java.io.OutputStreamWriter.flush(OutputStreamWriter.java:251) at java.base/java.io.BufferedWriter.flush(BufferedWriter.java:257) at java.base/java.io.PrintWriter.newLine(PrintWriter.java:568) at java.base/java.io.PrintWriter.println(PrintWriter.java:712) at java.base/java.io.PrintWriter.println(PrintWriter.java:823) at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl.start(DebugProtocolServerImpl.java:588) at com.oracle.truffle.tools.dap.instrument.DAPInstrument.launchServer(DAPInstrument.java:117) at com.oracle.truffle.tools.dap.instrument.DAPInstrument.onCreate(DAPInstrument.java:90) at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.TruffleInstrument$Env.onCreate(TruffleInstrument.java:661) at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler$InstrumentClientInstrumenter.create(InstrumentationHandler.java:2048) at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler.createInstrument(InstrumentationHandler.java:253) at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentAccessor$InstrumentImpl.createInstrument(InstrumentAccessor.java:123) at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotInstrument.ensureCreated(PolyglotInstrument.java:181) at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.ensureInstrumentsCreated(PolyglotEngineImpl.java:670) at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.createInstruments(PolyglotEngineImpl.java:664) at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineImpl.(PolyglotEngineImpl.java:328) at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotImpl.buildEngine(PolyglotImpl.java:288) at org.graalvm.sdk/org.graalvm.polyglot.Engine$Builder.build(Engine.java:625) at org.graalvm.sdk/org.graalvm.polyglot.Context$Builder.build(Context.java:1851) at org.truffleruby.launcher.RubyLauncher.runContext(RubyLauncher.java:269) at org.truffleruby.launcher.RubyLauncher.runRubyMain(RubyLauncher.java:254) at org.truffleruby.launcher.RubyLauncher.launch(RubyLauncher.java:129) at org.graalvm.launcher.AbstractLanguageLauncher.launch(AbstractLanguageLauncher.java:296) at org.graalvm.launcher.AbstractLanguageLauncher.launch(AbstractLanguageLauncher.java:121) at org.graalvm.launcher.AbstractLanguageLauncher.runLauncher(AbstractLanguageLauncher.java:168) Caused by: java.lang.NullPointerException at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl$ConsoleOutputListener.outputText(DebugProtocolServerImpl.java:696) at com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream.wl(OutputHandler.java:92) at com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream.write(OutputHandler.java:78) at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.writeMulti(DispatchOutputStream.java:210) ... 30 more [Graal DAP] Starting server and listening on localhost/127.0.0.1:9472 [Graal DAP] Client connected on /127.0.0.1:56787 ```

nirvdrum commented 2 years ago

FYI, I didn't see this when TruffleRuby was using Graal 2ed7b572d8e2deb56587a8ba7550749f1c91e925. The problem started TruffleRuby imported Graal 3abb64734edf5c2f12a557ac4d5674cf27758a75.

nirvdrum commented 2 years ago

In a subsequent session where I tried to disable DAP from pausing on the first line, I saw the following trace. I think it's the same as the original issue, but I can't be sure. It has deeper stack information. If it's unrelated, I can file a separate issue.

java.lang.Exception: Output operation write(B[II) failed for com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream@6b5ca753.
        at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.handleException(DispatchOutputStream.java:274)
        at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.writeMulti(DispatchOutputStream.java:216)
        at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream.write(DispatchOutputStream.java:130)
        at java.base/sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:233)
        at java.base/sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:312)
        at java.base/sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:316)
        at java.base/sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:153)
        at java.base/java.io.OutputStreamWriter.flush(OutputStreamWriter.java:251)
        at java.base/java.io.BufferedWriter.flush(BufferedWriter.java:257)
        at java.base/java.io.PrintWriter.newLine(PrintWriter.java:568)
        at java.base/java.io.PrintWriter.println(PrintWriter.java:712)
        at java.base/java.io.PrintWriter.println(PrintWriter.java:840)
        at java.base/java.lang.Throwable$WrappedPrintWriter.println(Throwable.java:768)
        at java.base/java.lang.Throwable.printStackTrace(Throwable.java:659)
        at java.base/java.lang.Throwable.printStackTrace(Throwable.java:725)
        at com.oracle.truffle.tools.dap.instrument.DAPInstrument.lambda$launchServer$2(DAPInstrument.java:118)
        at java.base/java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:986)
        at java.base/java.util.concurrent.CompletableFuture$UniExceptionally.tryFire(CompletableFuture.java:970)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1742)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.NullPointerException
        at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl$ConsoleOutputListener.outputText(DebugProtocolServerImpl.java:696)
        at com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream.wl(OutputHandler.java:92)
        at com.oracle.truffle.tools.dap.server.OutputHandler$ListeneableOutputStream.write(OutputHandler.java:78)
        at org.graalvm.truffle/com.oracle.truffle.api.impl.DispatchOutputStream$OutputStreamList.writeMulti(DispatchOutputStream.java:210)
        ... 21 more
java.util.concurrent.CompletionException: java.lang.IllegalStateException: There is no current context available.
        at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
        at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
        at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1739)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: There is no current context available.
        at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineException.illegalState(PolyglotEngineException.java:135)
        at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotContextImpl.requireContext(PolyglotContextImpl.java:720)
        at org.graalvm.truffle/com.oracle.truffle.polyglot.EngineAccessor$EngineImpl.getTruffleFile(EngineAccessor.java:275)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.TruffleInstrument$Env.getTruffleFile(TruffleInstrument.java:778)
        at com.oracle.truffle.tools.dap.server.LoadedSourcesHandler.getPath(LoadedSourcesHandler.java:177)
        at com.oracle.truffle.tools.dap.server.LoadedSourcesHandler.from(LoadedSourcesHandler.java:157)
        at com.oracle.truffle.tools.dap.server.LoadedSourcesHandler.assureLoaded(LoadedSourcesHandler.java:134)
        at com.oracle.truffle.tools.dap.server.LoadedSourcesHandler.onLoad(LoadedSourcesHandler.java:64)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler.notifySourceLoadedBinding(InstrumentationHandler.java:734)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler.notifySourceLoadedBindings(InstrumentationHandler.java:727)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler$1.accept(InstrumentationHandler.java:119)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler$1.accept(InstrumentationHandler.java:116)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.SourceInstrumentationHandler$AllSourcesNotification.runNotifications(SourceInstrumentationHandler.java:407)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.SourceInstrumentationHandler$SourcesNotificationQueue.process(SourceInstrumentationHandler.java:312)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler.addSourceLoadedBinding(InstrumentationHandler.java:412)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler.attachSourceListener(InstrumentationHandler.java:873)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler$AbstractInstrumenter.attachLoadSourceListener(InstrumentationHandler.java:2376)
        at org.graalvm.truffle/com.oracle.truffle.api.instrumentation.InstrumentationHandler$AbstractInstrumenter.attachLoadSourceListener(InstrumentationHandler.java:2382)
        at com.oracle.truffle.tools.dap.server.ExecutionContext.initSession(ExecutionContext.java:72)
        at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl.connect(DebugProtocolServerImpl.java:552)
        at com.oracle.truffle.tools.dap.types.DebugProtocolServer$Session.<init>(DebugProtocolServer.java:252)
        at com.oracle.truffle.tools.dap.types.DebugProtocolServer$Session.connect(DebugProtocolServer.java:769)
        at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl$4.run(DebugProtocolServerImpl.java:624)
        at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1736)
        ... 3 more

nirvdrum commented 2 years ago

Another stack trace when I boot is:

[Graal DAP] Starting server and listening on localhost/127.0.0.1:20581
[Graal DAP] Client connected on /127.0.0.1:53873
[To redirect Truffle log output to a file use one of the following options:
* '--log.file=<path>' if the option is passed using a guest language launcher.
* '-Dpolyglot.log.file=<path>' if the option is passed using the host Java launcher.
* Configure logging using the polyglot embedding API.]
[dap] SEVERE: Index 56 out of bounds for length 0
java.lang.IndexOutOfBoundsException: Index 56 out of bounds for length 0
        at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
        at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
        at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
        at java.base/java.util.Objects.checkIndex(Objects.java:372)
        at java.base/java.util.ArrayList.get(ArrayList.java:459)
        at com.oracle.truffle.tools.dap.server.LoadedSourcesHandler.getSource(LoadedSourcesHandler.java:80)
        at com.oracle.truffle.tools.dap.server.BreakpointsHandler.setBreakpoints(BreakpointsHandler.java:88)
        at com.oracle.truffle.tools.dap.server.DebugProtocolServerImpl.setBreakpoints(DebugProtocolServerImpl.java:295)
        at com.oracle.truffle.tools.dap.types.DebugProtocolServer$Session.processRequest(DebugProtocolServer.java:479)
        at com.oracle.truffle.tools.dap.types.DebugProtocolServer$Session.processMessage(DebugProtocolServer.java:406)
        at com.oracle.truffle.tools.dap.types.DebugProtocolServer$Session.run(DebugProtocolServer.java:343)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)

entlicher commented 2 years ago

The NPE is fixed by https://github.com/oracle/graal/commit/c2077395f463a80d7bd186cbef5189aa1e34ccb4 The IndexOutOfBoundsException is being addressed in https://github.com/oracle/graal/issues/4944

entlicher commented 1 year ago

There is also:

Caused by: java.lang.IllegalStateException: There is no current context available.
        at org.graalvm.truffle/com.oracle.truffle.polyglot.PolyglotEngineException.illegalState(PolyglotEngineException.java:135)

This is addressed by https://github.com/oracle/graal/commit/56d718f8d90210fcb98a2a33ae6c32716db2eccf

oracle / graal

NPE starting VS Code debugger #5143