formatting requests/didChange/didOpen appear to be sent out of order for global search-and-replace + formatOnSave

Hello!

I am an author of the trunk extension (https://marketplace.visualstudio.com/items?itemName=Trunk.io). We have users reporting bugs that when they set the trunk extension as the default formatter and run enable formatOnSave, they have global search-and-replace reverted by the extension.

It appears this is due to requests and notifications sent out of order. Here is an example trace (on a previously closed file) -

[Trace - 11:39:28 AM] Sending request 'textDocument/formatting - (207)'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh"
    },
    "options": {
        "tabSize": 4,
        "insertSpaces": true
    }
}


[Trace - 11:39:28 AM] Sending notification 'textDocument/didChange'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh",
        "version": 84
    },
    "contentChanges": [
        {
            "text": "#pragma once\n\n// asdfkjghatjhkjghakasdlfkjaslrakjglaksdjtlawkjglaskdjgasdgaljtlkaewjglakjgawlekasdlgkjasdglkj asdfkjghatjhkjghakasdlfkjaslrakjglaksdjtlawkjglaskdjgasdgaljtlkaewjglakjgawlekasdlgkjasdglkj asdfkjghatjhkjghakasdlfkjaslrakjglaksdjtlawkjglaskdjgasdgaljtlkaewjglakjgawlekasdlgkjasdglkj\nnamespace trunk::bar {}  // namespace trunk::bar\n"
        }
    ]
}


[Trace - 11:39:28 AM] Sending notification 'textDocument/didOpen'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh",
        "languageId": "cpp",
        "version": 83,
        "text": "#pragma once\n\n// abcdef abcdef abcdef\nnamespace trunk::bar {}  // namespace trunk::bar\n"
    }
}


[Trace - 11:39:29 AM] Received response 'textDocument/formatting - (207)' in 1132ms.
Result: [
    {
        "newText": "#pragma once\n\n// abcdef abcdef abcdef\nnamespace trunk::bar {}  // namespace trunk::bar",
        "range": {
            "end": {
                "character": 4611686018427388000,
                "line": 4611686018427388000
            },
            "start": {
                "character": 0,
                "line": 0
            }
        }
    }
]


[Trace - 11:39:29 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {
    "diagnostics": [],
    "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh"
}


[Trace - 11:39:29 AM] Sending notification 'textDocument/didClose'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh"
    }
}


[Trace - 11:39:29 AM] Sending notification 'textDocument/didChange'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh",
        "version": 86
    },
    "contentChanges": [
        {
            "text": "#pragma once\n\n// abcdef abcdef abcdef\nnamespace trunk::bar {}  // namespace trunk::bar\n"
        }
    ]
}


[Trace - 11:39:29 AM] Sending notification 'textDocument/didSave'.
Params: {
    "textDocument": {
        "uri": "file:///home/lauri/work/trunk/trunk/cli/actions/foo.hh"
    }
}

As the formatting requests occurs prior to the didChange (which is also before didOpen), it formats the old text of the file and thus the search-and-replace fails.

Presumably, the correct order should be didOpen - didChange - formatting. This may be related to #1105, although I am not sure if the fix there handles the out of order formatting request.

Let me know if you need any more info. Much appreciated!

Lauri Takacsi (@laurit17)

Lauri Takacsi (@laurit17) which version of the LSP libraries are you using?

There were two bugs around didOpen / didChange. They only occur with full text document sync (are you using that) and got fixed in 8.1.0-next.2 of the client libs.

Dirk Bäumer (@dbaeumer)

Hi Dirk Bäumer (@dbaeumer) , sorry for not providing that info, we are using 8.0.2. And yes we are using full text document sync.

I tried with 8.1.0-next.2, the events appear to be closer to being in order (formatting request occurs after the didOpen but unfortunately before the didChange).

[Trace - 11:35:01 AM] Sending notification 'textDocument/didOpen'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts",
        "languageId": "typescript",
        "version": 29,
        "text": "// abcdef abcdef abcdef\n"
    }
}


[Trace - 11:35:01 AM] Sending request 'textDocument/formatting - (38)'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts"
    },
    "options": {
        "tabSize": 2,
        "insertSpaces": true
    }
}


[Trace - 11:35:01 AM] Sending notification 'textDocument/didChange'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts",
        "version": 30
    },
    "contentChanges": [
        {
            "text": "// asldfkjasdflaksdjfalsdkfjasldfkjasdflkajsdflaskdjfalskfjasldfkjasdlfkjasdlfkjasdlfkj asldfkjasdflaksdjfalsdkfjasldfkjasdflkajsdflaskdjfalskfjasldfkjasdlfkjasdlfkjasdlfkj asldfkjasdflaksdjfalsdkfjasldfkjasdflkajsdflaskdjfalskfjasldfkjasdlfkjasdlfkjasdlfkj\n"
        }
    ]
}


[Trace - 11:35:01 AM] Received response 'textDocument/formatting - (38)' in 532ms.
Result: [
    {
        "newText": "// abcdef abcdef abcdef\n",
        "range": {
            "end": {
                "character": 4611686018427388000,
                "line": 4611686018427388000
            },
            "start": {
                "character": 0,
                "line": 0
            }
        }
    }
]


[Trace - 11:35:01 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {
    "diagnostics": [],
    "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts"
}


[Trace - 11:35:01 AM] Sending notification 'textDocument/didClose'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts"
    }
}


[Trace - 11:35:01 AM] Sending notification 'textDocument/didChange'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts",
        "version": 31
    },
    "contentChanges": [
        {
            "text": "// abcdef abcdef abcdef\n"
        }
    ]
}


[Trace - 11:35:01 AM] Sending notification 'textDocument/didSave'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts"
    }
}


[Trace - 11:35:01 AM] Received notification 'textDocument/publishDiagnostics'.
Params: {
    "diagnostics": [],
    "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts"
}


[Trace - 11:35:02 AM] Sending request 'textDocument/codeAction - (39)'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/formattingProvider.ts"
    },
    "range": {
        "start": {
            "line": 15,
            "character": 38
        },
        "end": {
            "line": 15,
            "character": 38
        }
    },
    "context": {
        "diagnostics": [],
        "triggerKind": 2
    }
}


[Trace - 11:35:02 AM] Received response 'textDocument/codeAction - (39)' in 1ms.
Result: []


[Trace - 11:35:03 AM] Sending notification 'textDocument/didOpen'.
Params: {
    "textDocument": {
        "uri": "file:///Users/lauri/work/trunk/trunk/vscode/src/formatting/foo.ts",
        "languageId": "typescript",
        "version": 31,
        "text": "// abcdef abcdef abcdef\n"
    }
}

Let me know if I can provide any more info.

Lauri Takacsi (@laurit17)

Lauri Takacsi (@laurit17)

can you please provide me with the user facing steps that are done to reproduce this. Something like

open file
search for abc
replace ....
....

Hello, I've attached a Loom that demonstrates the bug in a small trunk-enabled repo -https://www.loom.com/share/14fea7c6185b46dc8d86d7946f3fb5c1

Minimal repro -
https://github.com/laurit17/trunk-format-on-save-bug

install trunk - https://marketplace.visualstudio.com/items?itemName=Trunk.io

I recommend pausing the linters by pressing the stop button here -

close all files
do a global search-and-replace on abcdef with a long string (to force a re-format) - a few of the files have a comment like // abcdef abcdef abcdef
open the files to see whether the formatting was applied with the replaced text, or the original text.

in the case of this demo, it looks like it happens some of the time.

Inspecting the requests shows that the formatting request occurs before the didChange event some of the time. We are still on 8.0.2 for the vscode SDK, but I will push out a new release with 8.1.0-next.2 and verify this is still occurring (which I observed in an extension host).

Thank you so much for your support so far.

Just as an additional note, published version 3.3.5 of our extension to the market place that includes the latest version of 8.1.0-next.2.

I was able to reproduce this but it needs some thinking on how to best fix it.

Dirk Bäumer (@dbaeumer)

Hi Dirk Bäumer (@dbaeumer) , thank you so much for your fast follow up on this! Can you give an idea of when to expect a release? Thank you!

I released client@8.1.0-next.3 and server@8.1.0-next.3 which contain the fix. I would happy if you could give them a try and see if the issue is fixed for you.

Hi, this fixes the issue. Thank you so much!!

Fixes microsoft#1133: formatting requests/didChange/didOpen appear to…

Navigation Menu

Repository navigation

formatting requests/didChange/didOpen appear to be sent out of order for global search-and-replace + formatOnSave #1133

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

formatting requests/didChange/didOpen appear to be sent out of order for global search-and-replace + formatOnSave #1133

Description

Activity

dbaeumer commented on Dec 5, 2022

laurit17 commented on Dec 5, 2022

laurit17 commented on Dec 5, 2022

dbaeumer commented on Dec 6, 2022

laurit17 commented on Dec 6, 2022

laurit17 commented on Dec 8, 2022

dbaeumer commented on Dec 8, 2022

laurit17 commented on Dec 9, 2022

dbaeumer commented on Dec 12, 2022

laurit17 commented on Dec 12, 2022

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions