Server fails to start when specific models are in current directory

[syyyr]

Hi, I'm not sure when, but at some point the server stopped working for me. I suspect it is because of some sort of a system update, but I'm not sure. I use Arch Linux. This is the error message I get:

2021-05-25T10:23:05.205 INFO (pid:222822) [services] - registered service "languageserver.yang"
2021-05-25T10:23:05.210 INFO (pid:222822) [services] - yang state change: stopped => starting
2021-05-25T10:23:05.286 INFO (pid:222822) [language-client-index] - Language server "languageserver.yang" started with 222847
2021-05-25T10:23:05.294 INFO (pid:222822) [services] - registered service "clangd"
2021-05-25T10:23:06.232 INFO (pid:222822) [services] - registered service "diagnostic-languageserver"
2021-05-25T10:23:06.237 INFO (pid:222822) [plugin] - coc.nvim 0.0.80-971c5f81b4 initialized with node: v16.2.0 after 1145ms
2021-05-25T10:23:13.929 INFO (pid:222822) [services] - yang state change: starting => stopped
2021-05-25T10:23:13.932 ERROR (pid:222822) [services] - Server languageserver.yang failed to start: ResponseError2: Internal error.
    at handleResponse (/home/vk/.local/share/nvim/site/pack/bundle/opt/coc.nvim/build/index.js:13742:38)
    at processMessageQueue (/home/vk/.local/share/nvim/site/pack/bundle/opt/coc.nvim/build/index.js:13597:11)
    at Immediate.<anonymous> (/home/vk/.local/share/nvim/site/pack/bundle/opt/coc.nvim/build/index.js:13583:9)
    at processImmediate (node:internal/timers:464:21) {
  code: -32603,
  data: 'java.util.concurrent.CompletionException: org.eclipse.emf.common.util.WrappedException: java.lang.IllegalStateException: Cannot add to phase, since the next phase has already been executed. Ignoring the callback\n' +
    '\tat java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)\n' +
    '\tat java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)\n' +
    '\tat java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)\n' +
    '\tat java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)\n' +
    '\tat java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)\n' +
    '\tat java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)\n' +
    '\tat org.eclipse.xtext.ide.server.concurrent.WriteRequest.run(WriteRequest.java:44)\n' +
    '\tat java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)\n' +
    '\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n' +
    '\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n' +
    '\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n' +
    '\tat java.lang.Thread.run(Thread.java:748)\n' +
    'Caused by: org.eclipse.emf.common.util.WrappedException: java.lang.IllegalStateException: Cannot add to phase, since the next phase has already been executed. Ignoring the callback\n' +
    '\tat org.eclipse.xtext.linking.lazy.LazyLinkingResource.getEObject(LazyLinkingResource.java:244)\n' +
    '\tat org.eclipse.xtext.linking.lazy.LazyLinkingResource.doResolveLazyCrossReference(LazyLinkingResource.java:203)\n' +
    '\tat org.eclipse.xtext.linking.lazy.LazyLinkingResource.resolveLazyCrossReference(LazyLinkingResource.java:162)\n' +
    '\tat org.eclipse.xtext.linking.lazy.LazyLinkingResource.resolveLazyCrossReferences(LazyLinkingResource.java:148)\n' +
    '\tat org.eclipse.xtext.EcoreUtil2.resolveLazyCrossReferences(EcoreUtil2.java:504)\n' +
    '\tat org.eclipse.xtext.build.IncrementalBuilder$InternalStatefulIncrementalBuilder.lambda$launch$2(IncrementalBuilder.java:265)\n' +
    '\tat com.google.common.collect.Iterators$6.transform(Iterators.java:783)\n' +
    '\tat com.google.common.collect.TransformedIterator.next(TransformedIterator.java:47)\n' +
    '\tat com.google.common.collect.FluentIterable.copyInto(FluentIterable.java:791)\n' +
    '\tat org.eclipse.xtext.build.ClusteringStorageAwareResourceLoader.executeClustered(ClusteringStorageAwareResourceLoader.java:68)\n' +
    '\tat org.eclipse.xtext.build.BuildContext.executeClustered(BuildContext.java:54)\n' +
    '\tat org.eclipse.xtext.build.IncrementalBuilder$InternalStatefulIncrementalBuilder.launch(IncrementalBuilder.java:258)\n' +
    '\tat org.eclipse.xtext.build.IncrementalBuilder.build(IncrementalBuilder.java:403)\n' +
    '\tat org.eclipse.xtext.build.IncrementalBuilder.build(IncrementalBuilder.java:385)\n' +
    '\tat org.eclipse.xtext.ide.server.ProjectManager.doBuild(ProjectManager.java:105)\n' +
    '\tat org.eclipse.xtext.ide.server.ProjectManager.doInitialBuild(ProjectManager.java:96)\n' +
    '\tat org.eclipse.xtext.ide.server.BuildManager.doInitialBuild(BuildManager.java:172)\n' +
    '\tat org.eclipse.xtext.ide.server.WorkspaceManager.refreshWorkspaceConfig(WorkspaceManager.java:172)\n' +
    '\tat org.eclipse.xtext.ide.server.WorkspaceManager.initialize(WorkspaceManager.java:145)\n' +
    '\tat org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$initialize$0(LanguageServerImpl.java:220)\n' +
    '\tat org.eclipse.xtext.ide.server.concurrent.WriteRequest.run(WriteRequest.java:38)\n' +
    '\t... 5 more\n' +
    'Caused by: java.lang.IllegalStateException: Cannot add to phase, since the next phase has already been executed. Ignoring the callback\n' +
    '\tat io.typefox.yang.scoping.ScopeContext.onResolveDefinitions(ScopeContext.java:524)\n' +
    '\tat io.typefox.yang.scoping.LocalScopeContext.onResolveDefinitions(LocalScopeContext.java:82)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider._computeScope(ScopeContextProvider.java:450)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.computeScope(ScopeContextProvider.java:1223)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.handleGeneric(ScopeContextProvider.java:755)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider._computeScope(ScopeContextProvider.java:398)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.computeScope(ScopeContextProvider.java:1226)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.handleGeneric(ScopeContextProvider.java:755)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider._computeScope(ScopeContextProvider.java:398)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.computeScope(ScopeContextProvider.java:1226)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.handleGeneric(ScopeContextProvider.java:755)\n' +
    '\tat io.typefox.yang.scoping.ScopeContextProvider.getScopeContext(ScopeContextProvider.java:290)\n' +
    '\tat io.typefox.yang.resource.YangResource.getEObject(YangResource.java:27)\n' +
    '\tat org.eclipse.xtext.linking.lazy.LazyLinkingResource.getEObject(LazyLinkingResource.java:236)\n' +
    '\t... 25 more\n'
}
2021-05-25T10:23:20.312 INFO (pid:222822) [attach] - receive notification: showInfo []

Do you know what causes this? I tried using version 0.3.1, 0.4.0, and current master. Although I do remember, that it did work at some point and then stopped working (without changing the version of yang-lsp).

[dhuebner]

@syyyr The stack trace above seem to be not from master, right? It's difficult to say without a reproducible example. Yang lsp scoping process computation in different phases, the error message says that somehow a processing request was added to phase A where phase A already finished and phase B is started.

[syyyr]

Okay, I did some research on this. The error only happens if my current directory has this kind structure:

$ ls
first.yang  other.yang

Contents of the files: first.yang:

submodule first {
    include other;
}

other.yang

submodule other {
}

If I try to run the server with these files in my current directory, the server fails with an error. This error is a bit different than what I posted in the original post: here is the log. The version is current master.

If I remove one of the files, or remove the include statement, the server runs fine and works correctly (for this example, it says that a submodule needs a belongs-to statement - which is correct).

I don't know how to run the server without coc.nvim (which serves is my LSP client), but I would be glad to follow your instructions on how to run the server without it. Just running the executable seems to do nothing (I know nothing about LSP communication).

[dhuebner]

@syyyr

This error is a bit different

The error is very different from the original post. This error is a NullPointer exception because of missing belongs-to. I Fixed that in current master.

There must be a different constellation of module/submodule/import that causes the original exception you posted. Please try to reproduce your exception with the current state. It looks like a bad bug in the current scoping implementation and I would like to fix it.

[syyyr]

The current version now fixes the null pointer exception.

How to reproduce the other error: 1) Put these files into your working directory:

• https://github.com/CESNET/libyang/blob/e24ac91f03896008acc1664d4b3912fb6eea9a79/tests/schema/yang/files/submod1.yang
• https://github.com/CESNET/libyang/blob/e24ac91f03896008acc1664d4b3912fb6eea9a79/tests/schema/yang/files/submod_r%402016-06-20.yang 2) The server fails to start.

Side note: the way I found out about this is that I use libyang as a submodule in my main repository. That's why everytime I opened a .yang file, the server would recurse into the submodule and crash on libyang's schemas. Even my previous reproducer is based on these two files. It might be possible that more errors would occur if one were to copy all of the yang schemas from the tests/schema/yang/files subdirectory to their working directory.

[dhuebner]

@syyyr The exception occurs because the main_mod doesn't exists e.g. here belongs-to main_mod This should definitely not prevent the language server to start. I added a try catch around the problematic call, you will probably see the exception logged, but the server should start anyway. Please try the current master state

[syyyr]

With the new version, I can no longer reproduce this bug, so I'm closing this issue. Thank you for the fix. I do have another problem, but I think I'll create a new issue for that.