Index out of bounds panic in line index

[tvallotton]

Rust analyzer panicked while commenting some code. I haven't been able to reproduce the issue, but I decided to give you the output just in case. I was commenting either the ast::Statement enum or its Display implementation. If it helps the code I had can be found at https://github.com/tvallotton/sqlparser-rs/tree/rust-analyzer-panic.

Panic context:
> 
version: d15f646ff 2021-08-30 stable
request: codeLens/resolve CodeLens {
    range: Range {
        start: Position {
            line: 1351,
            character: 11,
        },
        end: Position {
            line: 1351,
            character: 19,
        },
    },
    command: None,
    data: Some(
        Object({
            "impls": Object({
                "textDocument": Object({
                    "uri": String(
                        "file:///Users/tomas/Documents/sqlparser-rs/src/ast/mod.rs",
                    ),
                }),
                "position": Object({
                    "line": Number(
                        1351,
                    ),
                    "character": Number(
                        11,
                    ),
                }),
            }),
        }),
    ),
}

thread '<unnamed>' panicked at 'index out of bounds: the len is 1153 but the index is 1351', crates/ide_db/src/line_index.rs:106:9
stack backtrace:
   0: _rust_begin_unwind
   1: core::panicking::panic_fmt
   2: core::panicking::panic_bounds_check
   3: rust_analyzer::from_proto::text_range
   4: rust_analyzer::handlers::handle_code_lens_resolve
   5: rust_analyzer::dispatch::RequestDispatcher::on::{{closure}}::{{closure}}
   6: <F as threadpool::FnBox>::call_box
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[Error - 11:44:57 AM] Request codeLens/resolve failed.
  Message: server panicked: index out of bounds: the len is 1153 but the index is 1351
  Code: -32603 
Panic context:
> 
version: d15f646ff 2021-08-30 stable
request: codeLens/resolve CodeLens {
    range: Range {
        start: Position {
            line: 1334,
            character: 9,
        },
        end: Position {
            line: 1334,
            character: 20,
        },
    },
    command: None,
    data: Some(
        Object({
            "impls": Object({
                "textDocument": Object({
                    "uri": String(
                        "file:///Users/tomas/Documents/sqlparser-rs/src/ast/mod.rs",
                    ),
                }),
                "position": Object({
                    "line": Number(
                        1334,
                    ),
                    "character": Number(
                        9,
                    ),
                }),
            }),
        }),
    ),
}

thread '<unnamed>' panicked at 'index out of bounds: the len is 1153 but the index is 1334', crates/ide_db/src/line_index.rs:106:9
Panic context:
> 
version: d15f646ff 2021-08-30 stable
request: codeLens/resolve CodeLens {
    range: Range {
        start: Position {
            line: 1321,
            character: 11,
        },
        end: Position {
            line: 1321,
            character: 21,
        },
    },
    command: None,
    data: Some(
        Object({
            "impls": Object({
                "textDocument": Object({
                    "uri": String(
                        "file:///Users/tomas/Documents/sqlparser-rs/src/ast/mod.rs",
                    ),
                }),
                "position": Object({
                    "line": Number(
                        1321,
                    ),
                    "character": Number(
                        11,
                    ),
                }),
            }),
        }),
    ),
}

thread '<unnamed>' panicked at 'index out of bounds: the len is 1153 but the index is 1321', crates/ide_db/src/line_index.rs:106:9
stack backtrace:
Panic context:
> 
version: d15f646ff 2021-08-30 stable
request: codeLens/resolve CodeLens {
    range: Range {
        start: Position {
            line: 1351,
            character: 11,
        },
        end: Position {
            line: 1351,
            character: 19,
        },
    },
    command: None,
    data: Some(
        Object({
            "impls": Object({
                "textDocument": Object({
                    "uri": String(
                        "file:///Users/tomas/Documents/sqlparser-rs/src/ast/mod.rs",
                    ),
                }),
                "position": Object({
                    "line": Number(
                        1351,
                    ),
                    "character": Number(
                        11,
                    ),
                }),
            }),
        }),
    ),
}

thread '<unnamed>' panicked at 'index out of bounds: the len is 1153 but the index is 1351', crates/ide_db/src/line_index.rs:   0: _rust_begin_unwind106
 :  91: 
core::panicking::panic_fmt
   2: core::panicking::panic_bounds_check
   3: rust_analyzer::from_proto::text_range
   4: rust_analyzer::handlers::handle_code_lens_resolve
   5: rust_analyzer::dispatch::RequestDispatcher::on::{{closure}}::{{closure}}
   6: <F as threadpool::FnBox>::call_box
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
   0: _rust_begin_unwind
   1: core::panicking::panic_fmt
   2: core::panicking::panic_bounds_check
   3: rust_analyzer::from_proto::text_range
   4: rust_analyzer::handlers::handle_code_lens_resolve
   5: rust_analyzer::dispatch::RequestDispatcher::on::{{closure}}::{{closure}}
   6: <F as threadpool::FnBox>::call_box
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
   0: _rust_begin_unwind
   1: core::panicking::panic_fmt
   2: core::panicking::panic_bounds_check
   3: rust_analyzer::from_proto::text_range
   4: rust_analyzer::handlers::handle_code_lens_resolve
   5: rust_analyzer::dispatch::RequestDispatcher::on::{{closure}[Error - 11:45:12 AM] Request codeLens/resolve failed.
  Message: server panicked: index out of bounds: the len is 1153 but the index is 1334
  Code: -32603 
}::{{closure}}
   6: <F as threadpool::FnBox>::call_box
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[Error - 11:45:12 AM] Request codeLens/resolve failed.
  Message: server panicked: index out of bounds: the len is 1153 but the index is 1321
  Code: -32603 
[Error - 11:45:12 AM] Request codeLens/resolve failed.
  Message: server panicked: index out of bounds: the len is 1153 but the index is 1351
  Code: -32603 

[tvallotton]

I think I was able to reproduce it. I wasn't commenting the code, I was deleting it. If you try deleting lines 547 to 1317 of src/ast/mod.rs the panic should occur.

[lnicola]

Ugh, this looks bad. And it's not that easy to reproduce, I can't trigger it.

[lnicola]

Are you using VS Code or coc.nvim?

[tvallotton]

I'm using VS Code

[tvallotton]

It does not always work, but generally if a save the file recently with cmd-s and delete the code it works. I'm trying to see if I can get a simpler example. I've also noticed that if I comment all the code inside the match statement it still occurs, however, if I remove it, it does not longer trigger the panic. It may be something with the length of deleted code I guess.

[lnicola]

Maybe you could try to get a complete LSP trace by setting RA_LOG=lsp_server=debug,error and RA_LOG_FILE to some path. You can set them in Code, in rust-analyzer.server.extraEnv.

If this still works, you should get a trace of every LSP message between Code and the server. We don't have a replay tool yet, but in principle you should be able to reproduce the issue by replaying that log.

The thing I'm worried about is that the server and client view of the file gets desynchronized, so it's not the edit you're making, but the full edit history in that session.

Or maybe it's something else. Are you interacting with the code lenses? I think resolve should be called when clicking on one.

[lnicola]

Not a file, a JSON map with the two keys, one to enable logging and one to redirect the logs to a file (otherwise they spam the Code console).

[tvallotton]

is this ok? In my workspace settings I suppose.

{
    "RA_LOG=lsp_server": ["debug", "error"],
    "RA_LOG_FILE": "/Users/tomas/Documents/sqlparser-rs/output"
}

I can't get it to work.

[dzvon]

@tvallotton I think the right format is:

{
    "rust-analyzer.server.extraEnv": {
        "RA_LOG": "lsp_server=debug,error",
        "RA_LOG_FILE": "/Users/tomas/Documents/sqlparser-rs/output"
    }
}

[tvallotton]

Ok so I just pushed the logs at output.txt. If you need anything else just let me know.

[lnicola]

Yeah, it looks fine, but it's very short and I think it contains no edits. I would have expected something in the range of tens of MBs, with LSP being so verbose.

On the other hand, I'm not sure we're flushing the log, so the last line or two might be truncated.

[matklad]

One hypothesis I have is maybe the clined indeed sends DidChangeTextDocument between asking for code lens and asking to resolve a specific code lens? One way to debug this is to add an optional memdoc document version to codelens data and verify, in resolve, that it is the same.

But in general I think I see a bug here -- we shouldn't assume that between list/resolve calls the state of world doesn't change. We shouldn't be storying text ranges in the resolve data at all, for that matter.

Instead, we should use the pattern we employ for code actions and completion -- re-run the same query, and use id of the result as data.

[bencarter4185]

I'm not sure if this is relevant, but I have been getting errors when using rust-analyzer with VS Code, lately. I can't offer any backtraces but I can report that this was with nightly Rust (fully updated) as the default, and I was using the crate inline-python within the code, which relies on nightly Rust. rust-analyzer was also having trouble with macro calls in this crate so I had also disabled checking for macro-errors.

Changing back to stable Rust and removing this inline-python dependency appears to have removed any backtraces in the analyzer. Hope this helps. I can also try and capture some backtraces if desired.