On second run, Indexing step hangs forever

[tercenya]

environment:

elixir 1.16.2-otp-26 (asdf)
erlang 26.2.3 (asdf)
lexical main 29373d5816ae161c4cdceb4cce9e8f1c99e065bc
vscode 1.87.2 863d2581ecda6849923a2118d93a088b0745d9d6 arm64
lexical-lsp.lexical v0.0.14 (2024-02-25 20:43:09?)
macOS Sonoma 14.4.1 (23E224)

reproduction steps: rm -rf .lexical, open vscode in project folder. Lexical compiles and indexes successfully. Save a file OR restart vscode. Lexical compiles successfully but hangs forever while indexing. Setting Trace: Server to verbose shows:

2024-04-02 14:26:36.206 [info] [Trace - 2:26:36 PM] Received notification '$/progress'.
2024-04-02 14:26:36.206 [info] Params: {
    "value": {
        "message": "Indexing",
        "kind": "report",
        "percentage": 88
    },
    "token": 7
}

The percentage where it hangs is seemingly arbitrary (0-98%). There's no corresponding error or information in the logs. This behavior exhibited after I recently updated elixir/erlang to the latest dot releases, and recompiled lexical from main/HEAD.

Things I've tried:

• opening code apps/something instead of the umbrella root (still hangs in a similar manner on non-trivial apps)
• changing the subapps to compile in their own folders, disabling sharing of umbrella deps/build/mix.lock
• deleting .lexical/indexes folder indexes successfully, and subsequently hangs as above

Things that cause me concern: lexical.log:

2024-04-02T14:34:38.529739-05:00 warning: Could not expand [{:@, [line: 96, column: 16], [{:for, [line: 96, column: 17], nil}]}, :Metadata] into an alias. Please report this. 
2024-04-02T14:34:38.529797-05:00 warning: Could not expand module [{:@, [line: 96, column: 16], [{:for, [line: 96, column: 17], nil}]}, :Metadata]. Please report this.

This is a use of @for inside a defimpl, but it's calling into a submodule that's implemented by macro on all implementations: fields = @for.Metadata.fields(). The unit test passes; works as intended. Possibly implicates recent change https://github.com/lexical-lsp/lexical/pull/666 or it's not expanding the necessary macro first?

None of this repository is public, but send over instructions and I'd be happy to diagnose more. At worst, if this doesn't ring any other bells, I'll see about deriving a sample repo to demonstrate this further.

[scohen]

This is a use of @for inside a defimpl, but it's calling into a submodule that's implemented by macro on all implementations: fields = @for.Metadata.fields(). The unit test passes; works as intended. Possibly implicates recent change https://github.com/lexical-lsp/lexical/pull/666 or it's not expanding the necessary macro first?

This is fine, it's just saying it can't index those things. The indexer can't and will never be able to index all kinds of code.

Are you sure there are no crashes in the project.log? Also, are you sure the indexer is still running?

[tercenya]

I didn't think the @for was the culprit, but I assume we're looking for what causing the Indexing step to not finish... or fail to report as finished.

Also, are you sure the indexer is still running?

I see a start_lexical.sh and corresponding beam process for as long as vscode is running. ps ax | grep lexical | wc shows something starting and stopping.

Are you sure there are no crashes in the project.log?

Now that you point it out, I do see an error in project.log:

On first run:

2024-04-02T15:57:04.408553-05:00 error: Task #PID<0.1004.0> started from LXical.RemoteControl.Search.Store terminating, ** (MatchError) no match of right hand side value: nil, (lx_remote_control 0.5.0) lib/lexical/remote_control/search/indexer/extractors/function_definition.ex:71: LXical.RemoteControl.Search.Indexer.Extractors.FunctionDefinition.detail_range/3, (lx_remote_control 0.5.0) lib/lexical/remote_control/search/indexer/extractors/function_definition.ex:17: LXical.RemoteControl.Search.Indexer.Extractors.FunctionDefinition.extract/2, (lx_remote_control 0.5.0) lib/lexical/remote_control/search/indexer/source/reducer.ex:97: anonymous fn/2 in LXical.RemoteControl.Search.Indexer.Source.Reducer.apply_extractors/2, (elixir 1.16.2) lib/enum.ex:2528: Enum."-reduce/3-lists^foldl/2-0-"/3, (lx_remote_control 0.5.0) lib/lexical/remote_control/search/indexer/quoted.ex:19: anonymous fn/2 in LXical.RemoteControl.Search.Indexer.Quoted.index/2, (elixir 1.16.2) lib/macro.ex:640: anonymous fn/4 in Macro.do_traverse_args/4, (stdlib 5.2.1) lists.erl:1706: :lists.mapfoldl_1/3, (stdlib 5.2.1) lists.erl:1707: :lists.mapfoldl_1/3, Function: &:erlang.apply/2, Args: [#Function<3.93003056/1 in LXical.RemoteControl.Search.Indexer.async_chunks/3>, ...(numerous source files)

The 2nd run has the same error preceded by an attempt to commit the ets wal, which may have been left dirty?

2024-04-02T15:59:37.825524-05:00 notice: disk_log: repairing "/XXX/..lexical/indexes/ets/26.2.3/1.16.2/3/updates.wal" ...
2024-04-02T15:59:38.309452-05:00 info: backend reports stale

[scohen]

I'm thinking it's crashing in the middle and failing to report being done.

If you want to test yourself, it's pretty easy to run the indexer. Assuming all your projects (and lexical) are hosted in a common directory, go to the lexical directory and do the following

# in the lexical directory
iex -S mix

iex> <your project name as an atom> |> search_entries() |> Enum.to_list()

So, for lexical, the command would be :lexical |> search_entries() |> Enum.to_list().

[scohen]

The error you highlighted is likely the culprit. It would be helpful to do what I've illustrated above and give me the offending code. What's going on is that it can't find the do/end for the given function definition, and it crashes in a pattern match.

[tercenya]

Excellent, will do. It's almost beer-thirty here, will get back to you anon, need to disable a few supervisors to fire up iex.

[scohen]

need to disable a few supervisors to fire up iex

You shouldn't have to do anything, this is in the lexical directory.

[tercenya]

Ah now I gotcha, had to move some folders around; just needed this subapp to be symlinked one folder under lexical.

iex(2)> :cobalt |> search_entries() |> Enum.to_list()

** (EXIT from #PID<0.323.0>) shell process exited with reason: an exception was raised:
    ** (MatchError) no match of right hand side value: nil
        (remote_control 0.5.0) lib/lexical/remote_control/search/indexer/extractors/function_definition.ex:71: Lexical.RemoteControl.Search.Indexer.Extractors.FunctionDefinition.detail_range/3
        (remote_control 0.5.0) lib/lexical/remote_control/search/indexer/extractors/function_definition.ex:17: Lexical.RemoteControl.Search.Indexer.Extractors.FunctionDefinition.extract/2
        (remote_control 0.5.0) lib/lexical/remote_control/search/indexer/source/reducer.ex:97: anonymous fn/2 in Lexical.RemoteControl.Search.Indexer.Source.Reducer.apply_extractors/2
        (elixir 1.16.2) lib/enum.ex:2528: Enum."-reduce/3-lists^foldl/2-0-"/3
        (remote_control 0.5.0) lib/lexical/remote_control/search/indexer/quoted.ex:19: anonymous fn/2 in Lexical.RemoteControl.Search.Indexer.Quoted.index/2
        (elixir 1.16.2) lib/macro.ex:640: anonymous fn/4 in Macro.do_traverse_args/4
        (stdlib 5.2.1) lists.erl:1706: :lists.mapfoldl_1/3
        (stdlib 5.2.1) lists.erl:1707: :lists.mapfoldl_1/3

I'll see if I can find what source file is implicated on my end.

[tercenya]

I found the offending line. This is a macro for dispatching a %Call{method: "something"} into a GenServer#call/2 or #cast/2.

  defmacro define_call(method_name, genserver_method \\ :cast) do
    quote do
      def rpc_call(
            pid,
            call = %Call{
              method: unquote(method_name)
            }
          ),
          do: GenServer.unquote(genserver_method)(pid, call)
    end
  end

GenServer.unquote(genserver_method)(pid, call) is the culprit.

[scohen]

@tercenya Pushed a fix.

[tercenya]

I pulled your branch, working on my end. Thanks much!

As a side-note incase anyone searches for it later on, I originally stumbled upon this because VSCode doesn't subscribe to the "let it crash" model. When enough Indexing tasks had backlogged as incomplete, it would fail to start any new "Format-on-save" tasks, thus preventing you from saving open windows/buffers (!). But that can be a separate issue, if need be.

[scohen]

Thanks for the help in reproducing the error.

[scohen]

@tercenya can you also try the workspace-symbols branch? I think that won't break either.

[scohen]

When enough Indexing tasks had backlogged as incomplete, it would fail to start any new "Format-on-save" tasks

This is lexical's fault, it should return errors for all failed requests.

[tercenya]

can you also try the workspace-symbols branch? I think that won't break either.

pulled, built, exercised - seems good 👍🏻

This is lexical's fault, it should return errors for all failed requests.

ah, just didn't want to conflate the macro-parsing issue, one bug at a time

@scohen glad to help, thanks again.