Skip to content

Completion request and content change arrival order #968

Closed
Closed
Completion request and content change arrival order#968
Assignees
dbaeumer
Labels
bugIssue identified by VS Code Team member as probable bug

Description

@marcusroberts
Marcus Roberts (marcusroberts)
opened on May 26, 2022

Watching the trace for communications between the extension and the server, we see textDocument/completion get sent before textDocument/didChange, so we are looking at the source code as it was before the change was made.

When it's a trigger character we can add it on to the text before the cursor (although the cursor position is reported in the changed source that follows in the didChange) but when it's just invoked by being an identifier that identifier isn't in the source we hold.

What's the best way to handle this? Our own server is single threaded so we know it will process them in this order, but I guess other servers are async and could be processing both at the same time? Is there a guaranteed order that all clients will send these two in?

Activity

  1. rcjsuen commented on May 26, 2022

    @rcjsuen
    Remy Suen (rcjsuen)
    on May 26, 2022
    Contributor

    Watching the trace for communications between the extension and the server, we see textDocument/completion get sent before textDocument/didChange, so we are looking at the source code as it was before the change was made.

    This sounds like a bug that should be investigated. There are many language servers that work with Visual Studio Code so it's hard for me to believe this is a bug that is affecting everyone (myself included as I am the author of a language server myself).

    How can this bug be reproduced?

  2. marcusroberts commented on May 26, 2022

    @marcusroberts
    Marcus Roberts (marcusroberts)
    on May 26, 2022
    Author

    I can't believe it's a bug either because of its impact...

    This is for the Grain LSP I'm an author of. We moved up from a pretty old version of the client library to the latest as part of a major upgrade we are undertaking.

    In the Trace for our LSP we see this when we type a character at the start of a line for example:

    `[Trace - 7:46:01 AM] Sending request 'textDocument/completion - (99)'.
    Params: {
    "textDocument": {
    "uri": "file:///Users/marcus/Projects/tests/test.gr"
    },
    "position": {
    "line": 15,
    "character": 1
    },
    "context": {
    "triggerKind": 1
    }
    }

    [Trace - 7:46:01 AM] Sending notification 'textDocument/didChange'.
    Params: {
    "textDocument": {
    "uri": "file:///Users/marcus/Projects/tests/test.gr",
    "version": 104
    },
    "contentChanges": [
    {
    "text": "import Regex from "regex"\nimport Result from "result"\nimport List from "list"\nprint("Hello,Grain")\n\n10\n\nlet re = Result.unwrap(Regex.make("o"))\n\nprint(Regex.replace(re,"foo","bar"))\n\n\nlet fuu = 1\nlet foo = 2\n\nR\n"
    }
    ]
    }`

    and similarly for a completion character:

    `[Trace - 10:44:02 AM] Sending request 'textDocument/completion - (109)'.
    Params: {
    "textDocument": {
    "uri": "file:///Users/marcus/Projects/tests/test.gr"
    },
    "position": {
    "line": 16,
    "character": 5
    },
    "context": {
    "triggerKind": 2,
    "triggerCharacter": "."
    }
    }

    [Trace - 10:44:02 AM] Sending notification 'textDocument/didChange'.
    Params: {
    "textDocument": {
    "uri": "file:///Users/marcus/Projects/tests/test.gr",
    "version": 112
    },
    "contentChanges": [
    {
    "text": "import Regex from "regex"\nimport Result from "result"\nimport List from "list"\nprint("Hello,Grain")\n\n10\n\nlet re = Result.unwrap(Regex.make("o"))\n\nprint(Regex.replace(re,"foo","bar"))\n\n\nlet fuu = 1\nlet foo = 2\n\n\nList.\n\n"
    }
    ]
    }
    `

  3. DanTup commented on May 30, 2022

    @DanTup
    Danny Tuppeny (DanTup)
    on May 30, 2022
    Contributor

    FWIW, I don't see this behaviour with Dart, I see the didChange sent first:

    [12:01:24 PM] [Analyzer] [Info] ==> Content-Length: 379
[12:01:24 PM] [Analyzer] [Info] ==> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"file:///Users/danny/Dev/Google/dart-sdk/sdk/pkg/analysis_server/test/src/services/correction/fix/fix_in_file_test.dart","version":3},"contentChanges":[{"range":{"start":{"line":126,"character":4},"end":{"line":126,"character":4}},"rangeLength":0,"text":"()"}]},"clientRequestTime":1653908484135}
[12:01:24 PM] [Analyzer] [Info] ==> Content-Length: 338
[12:01:24 PM] [Analyzer] [Info] ==> {"jsonrpc":"2.0","id":28,"method":"textDocument/completion","params":{"textDocument":{"uri":"file:///Users/danny/Dev/Google/dart-sdk/sdk/pkg/analysis_server/test/src/services/correction/fix/fix_in_file_test.dart"},"position":{"line":126,"character":5},"context":{"triggerKind":2,"triggerCharacter":"("}},"clientRequestTime":1653908484135}

    However, my server is using incremental changes (textDocument/didChange contains only a delta). I don't know if that's affecting anything.

  4. DanTup commented on May 30, 2022

    @DanTup
    Danny Tuppeny (DanTup)
    on May 30, 2022
    Contributor

    Interestingly, in the code for full (non-incremental) sync, there is some field called changeDelayer. I don't know what it is, but perhaps it's related:

    vscode-languageserver-node/client/src/common/textSynchronization.ts

    Line 253 in b474786

    if (this._changeDelayer) {

    Perhaps it's an optimisation to reduce traffic for full sync (so every keystroke isn't sending the entire document), but the completion request isn't forcing delivery?

  5. marcusroberts commented on May 30, 2022

    @marcusroberts
    Marcus Roberts (marcusroberts)
    on May 30, 2022
    Author

    Danny Tuppeny (@DanTup) is that on the latest version? We are doing full change, I'll look at incremental too.

  6. DanTup commented on May 30, 2022

    @DanTup
    Danny Tuppeny (DanTup)
    on May 30, 2022
    Contributor

    Marcus Roberts (@marcusroberts) yep, that was on v8 of the client. Although based on the code I linked above, I suspect the issue could be specific to full sync.

  7. dbaeumer commented on May 30, 2022

    @dbaeumer
    Dirk Bäumer (dbaeumer)
    on May 30, 2022
    Member

    Regarding the change delayer. The flushing of buffered full document syncs is happening here:

    vscode-languageserver-node/client/src/common/client.ts

    Line 658 in e0064b3

    this.forceDocumentSync();

    and at the corresponding place in sendNotification

  8. dbaeumer commented on May 30, 2022

    @dbaeumer
    Dirk Bäumer (dbaeumer)
    on May 30, 2022
    Member

    I was actually able to reproduce this in full text document sync mode. Need to investigate why this is happening.

  9. dbaeumer commented on May 30, 2022

    @dbaeumer
    Dirk Bäumer (dbaeumer)
    on May 30, 2022
    Member

    The problem is that internally forceDocumentSync() is now async (send notification is async) and I need to await the force document sync.

    The reason this is not showing up in incremental sync is that there nothing is buffered.

  10. marcusroberts commented on May 30, 2022

    @marcusroberts
    Marcus Roberts (marcusroberts)
    on May 30, 2022
    Author

    I'm glad you could reproduce and then find the cause, and so quickly too, thank you!

  11. Dirk Bäumer (dbaeumer)
    added a commit that references this issue on May 30, 2022

    Fixes #968: Completion request and content change arrival order

    529ee89
  12. Dirk Bäumer (dbaeumer)
    added
    bugIssue identified by VS Code Team member as probable bug
    on May 30, 2022
  13. Dirk Bäumer (dbaeumer)
    self-assigned this
    on May 30, 2022
  14. Dirk Bäumer (dbaeumer)
    added this to the milestone on May 30, 2022
  15. Dirk Bäumer (dbaeumer)
    closed this as completedin 529ee89on May 30, 2022
  16. Dirk Bäumer (dbaeumer)
    added a commit that references this issue on May 30, 2022

    Merge pull request #972 from microsoft/dbaeumer/intelligent-ostrich-e…

    a6f0d22
  17. Dirk Bäumer (dbaeumer)
    modified the milestones: , on Jul 13, 2022
  18. Bastian Müller (turbolent)
    added a commit that references this issue on Jan 7, 2023

    update language client

    e9ab0eb
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

bugIssue identified by VS Code Team member as probable bug

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions