Metals: FailedToOpenBspConnection in vscode macos… JAVA_HOME issue in Catalina?

[hedefalk]

I'm starting on a new physical machine and I'm having problems with metals that I didn't have before. I think this is a Catalina jdk issue, but can't seem to figure out how it relates to vscode and metals.

So, when metals starts up on a project in vscode it triggers this native macos popup:

I have however set the metals JAVA_HOME setting:

In the log, this spits out simultaneously as the native macos popup

Java home: /Users/viktor/.jabba/jdk/[email protected]/Contents/Home
2020.05.11 12:19:28 INFO  logging to file /Users/viktor/dev/projects/kb-graph/.metals/metals.log
2020.05.11 12:19:28 INFO  started: Metals version 0.9.0 in workspace '/Users/viktor/dev/projects/kb-graph'
2020.05.11 12:19:29 INFO  time: initialize in 0.77s
Initializing Scala Debugger
2020.05.11 12:19:29 INFO  skipping build import with status 'Installed'
2020.05.11 12:19:29 INFO  no build target: using presentation compiler with only scala-library
2020.05.11 12:19:30 WARN  no build target for: /Users/viktor/dev/projects/kb-graph/seed/src/main/scala/MongoRead.scala
2020.05.11 12:19:31 ERROR Failed to connect with build server, no functionality will work.
java.lang.RuntimeException: The server did not start, got FailedToOpenBspConnection
    at bloop.launcher.LauncherMain.failPromise$1(Launcher.scala:95)
    at bloop.launcher.LauncherMain.runLauncher(Launcher.scala:122)
    at scala.meta.internal.metals.BloopServers$$anon$1.run(BloopServers.scala:107)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.lang.Thread.run(Thread.java:834)

Has it always been like this or have Apple changed the way java starts up? It doesn't seem to effect any of my cli usage - I'm able to start up this same project just fine using jabba or jenv:

❯ jabba use [email protected]
kb-graph on  master [!?] via ☕ v11.0.6
❯ java --version
openjdk 11.0.6 2020-01-14
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.6+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.6+10, mixed mode)
kb-graph on  master [!?] via ☕ v11.0.6
❯ which java
/Users/viktor/.jabba/jdk/[email protected]/Contents/Home/bin/java

Jabba not only sets JAVA_HOME but also prefix my path with /Users/viktor/.jabba/jdk/[email protected]/Contents/Home/bin. However, if running this without jabba setup I get the same horrid:

I thought this was the culprit at first - that something broke and I need the path and not only JAVA_HOME, but it also works fine just setting JAVA_HOME without the path prefix:

❯ java --version
No Java runtime present, requesting install. # i get the popup here too
~
✗ which java
/usr/bin/java
~
❯ set -x JAVA_HOME /Users/viktor/.jabba/jdk/[email protected]/Contents/Home/
~
❯ java --version
openjdk 11.0.6 2020-01-14
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.6+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.6+10, mixed mode)

But metals (or just bloop?) under vscode behaves just like I have no JAVA_HOME set.

To Reproduce
Steps to reproduce the behavior:

1. Install metals plugin in vscode.
2. Import project

Installation:

• Operating system: macOS 10.15.4
• Editor: Visual Studio Code
• Metals version: v0.9.0

[hedefalk]

Is it that only metals is using metals.javaHome and the forked bloop process just relies on JAVA_HOME? I'm really trying to be hygienic about polluting any global env… Couldn't metals set JAVA_HOME to metals.javaHome when forking the bloop process in that case?

Sorry, I'm just guessing here…

[tgodzik]

Thanks for reporting! We do use JAVA_HOME, but we do it this way when running Bloop:

https://github.com/scalacenter/bloop/blob/f69dd3ba74d81e71f6f1ca73a0b557055138d0b2/bloopgun/src/main/scala/bloop/bloopgun/Bloopgun.scala#L518-L549

So when we didn't find java on PATH then we use JAVA_HOME. However, if we never get an exception and just the pop-up shows then we might never use JAVA_HOME in that case.
We should most likely check for that message in Bloop then.

It's done this way to make sure that we use whatever is on PATH first and only then revert to JAVA_HOME, which is set by Metals or in the CLI.

[hedefalk]

Thanks for such a quick reply!

We do use JAVA_HOME

Not sure I understand. There is _always_ a java on path in MacOS, and its on /usr/bin/java. It's not even possible to delete this anymore, not even as su :) I guess this java binary looks at JAVA_HOME and starts a real java if there and pops up this error message otherwise…?

So if we fork the bloop process without passing a JAVA_HOME env through, that's whats gonna happen. And this is not an IOException so we don't catch it and retry, is that it?

To me it would make a lot of sense to pass the metals.javaHome to bloop since its supposed to be kindof an opaque sub-process?

Is there any bloop.javaHome or anything I can set from within vscode? I tried setting JAVA_HOME within vscode electron, but I still get the same behaviour… Hm…

[tgodzik]

So if we fork the bloop process without passing a JAVA_HOME env through, that's whats gonna happen. And this is not an IOException so we don't catch it and retry, is that it?

That's right. We do pass JAVA_HOME to Bloop, but it's only used when we have the expected exception.

here is always a java on path in MacOS, and its on /usr/bin/java. It's not even possible to delete this anymore, not even as su :)

This is something we certainly not anticipated. Is this a recent change?

I guess this java binary looks at JAVA_HOME and starts a real java if there and pops up this error message otherwise…?

So this "fake" binary will work if we set JAVA_HOME beforehand? We might be not adding that env variable when actually running the process.

For now I think the only workaround is to set the JAVA_HOME globally, but we should raise it on the Bloop issue tracker. I will need someone to check that out though, I don't have access to a MacOS machine.

[hedefalk]

Is this a recent change?

I thought _something_ was recent because I just started to get these popups in 10.15.4. However, I just asked @ennru here who's running a vintage 10.14.6 and he also has a /usr/bin/java. It might be that in the olden days it wasn't there unless a jre/jdk was installed however. And the whole protected system partition thingie is Catalina/10.15 new, I'm sure.

If I cat that binary I find texts about what it does. It's also very small.

cat (which java)

fhhhhhhh7hEhRhahqhh~hthjh`hVhLhBh8hC.hd$hhUnable to find a $JAVA_HOME at "%s", continuing with system-provided Java...
CommandLineUnable to locate a Java Runtime to invoke.
about to exec: "%s"
/usr/bin/javajava/usrJVMVersionobtained version: "%s"
JVMArchJAVA_ARCHset preferred architecture to: "%s"
JVMHomePathJAVA_HOME%sJVMName    %s, %s:        "%s"    %s
There do not appear to be any valid Java versions on this machine (NULL).
no JVMs matching version "%s":
There do not appear to be any valid Java versions on this machine (0).
JAVA_VERSIONgot environment variable %s: "%s"
available JVMs:
%s/bin/%s[JavaCommandLine] failed to spawn with err (%d)
failed to exec with err (%d)
Unable to launch "%s" (%d)
Unable to locate an executable at "%s" (%d)

So this "fake" binary will work if we set JAVA_HOME beforehand?

Yes, exactly:

❯ java --version
No Java runtime present, requesting install.
~
✗ set -x JAVA_HOME /Users/viktor/.jabba/jdk/[email protected]/Contents/Home/
~
✗ java --version
openjdk 11.0.6 2020-01-14
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.6+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.6+10, mixed mode)
~
❯

But that part is not new, I think passing a JAVA_HOME has always worked like that? Even the binaries of old delegated to the version under JAVA_HOME, didn't they?

Maybe the only new thing is that there is this pop-up generating binary there even though there are no system java's installed. That might have not been the case before and then the IOException catch would have worked…

I don't have access to a MacOS machine.

Let me know if I can help in any way :)

[hedefalk]

For now I think the only workaround is to set the JAVA_HOME globally

I can't get that working by setting system.env.JAVA_HOME in node, I really think that should work unless there's something weird with how the process is forked? I can only get it to work with having a JAVA_HOME set in my shell and starting vscode from there. If I start as an app in MacOS (not inheriting my login-shell) and subsequently setting JAVA_HOME from within node with

process.env.JAVA_HOME = "/Users/viktor/.jabba/jdk/[email protected]/Contents/Home/";

it still doesn't work. Is there something else that JAVA_HOME at play that I'm missing here? Or maybe I'm misunderstanding how the electron stack works, but I'm pretty sure I've been able to pass env to subprocesses of the electron node that way before…

[hedefalk]

I think I understand why now. I think that when this plugin loads, this code is run immediately:

https://github.com/scalameta/metals-languageclient/blob/master/src/getServerOptions.ts#L32

Since the deconstruction thing is used to merge system.env and extra env there, it's set in stone from there on. So even if I change the env in vscode, I'm still gonna get the same old env pushed to the subprocess.

I could probably test this by deactivating metals plugin, setting JAVA_HOME and reactivating again…

yes, that worked. So maybe it's better to stick that in a closure that reads system.env on the fly instead of at plugin activation time? Maybe I'm the only one gotten confused by this, but still :)

[tgodzik]

@hedefalk Glad you made it work! I wonder if it would make sense to set the JAVA_HOME to the javaHome setting if the JAVA_HOME is not set. That should help with situations like this.

So maybe it's better to stick that in a closure that reads system.env on the fly instead of at plugin activation time? Maybe I'm the only one gotten confused by this, but still :)

It should be read whenever we restart the server, but we cannot really read it on the fly since it requires rerunning the Metals server process.

[hedefalk]

It should be read whenever we restart the server, but we cannot really read it on the fly since it requires rerunning the Metals server process.

Yeah, currently even restarting the metals server is not enough since it is cached there in node by the stateful plugin. I'd have to do a change like this:

https://github.com/hedefalk/metals-languageclient/commit/ce50e16d7d32a4db560d28e0d3d0502269a82ed8

or restart vscode or go via a activate/deactivate plugin cycle to get any js settings reloaded from process.env.

[tgodzik]

@hedefalk would you mind creating a PR with that to the languageclient? I think it's a solid improvement.

[tgodzik]

Opened up PR for setting JAVA_HOME and together with @hedefalk changes. Hope that is alright!

[hedefalk]

Awesome! Thanks @tgodzik for looking into it so quickly. Tried your PR branch and it works fine for me with that :)