microsoft / vscode

Visual Studio Code
https://code.visualstudio.com
MIT License
162.38k stars 28.61k forks source link

Multiple Import Organizers results in corrupted code #174295

Open karthiknadig opened 1 year ago

karthiknadig commented 1 year ago

Type: Bug

Use two LSP servers have them both register provider of Organize Import code Action for the same language. When user runs Organize Imports both LSP servers receive the same version of the doc.

  1. The order in which they are run is not configurable.
  2. They don't seem to cascade the content of one into the other.
  3. There is nothing in the UI, or there are no warnings thay say two Import Organizers are registered.
  4. Also, there is no UI to select an import organizer like we can do with formatting.

Repro steps: You will need both isort and ruff extensions. See here: https://github.com/microsoft/vscode-isort/issues/240#issue-1583119337

VS Code version: Code 1.75.1 (441438abd1ac652551dbe4d408dfcec8a499b8bf, 2023-02-08T21:32:34.589Z) OS version: Windows_NT x64 10.0.19045 Modes: Sandboxed: No

System Info |Item|Value| |---|---| |CPUs|Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz (8 x 1498)| |GPU Status|2d_canvas: enabled
canvas_oop_rasterization: disabled_off
direct_rendering_display_compositor: disabled_off_ok
gpu_compositing: enabled
multiple_raster_threads: enabled_on
opengl: enabled_on
rasterization: enabled
raw_draw: disabled_off_ok
skia_renderer: enabled_on
video_decode: enabled
video_encode: enabled
vulkan: disabled_off
webgl: enabled
webgl2: enabled
webgpu: disabled_off| |Load (avg)|undefined| |Memory (System)|31.59GB (15.19GB free)| |Process Argv|--crash-reporter-id a228f424-c4b5-46af-9d39-ca54fee042cd| |Screen Reader|no| |VM|0%|
Extensions (24) Extension|Author (truncated)|Version ---|---|--- tsl-problem-matcher|amo|0.6.2 ruff|cha|2023.6.0 vscode-eslint|dba|2.4.0 gitlens|eam|13.2.0 EditorConfig|Edi|0.16.4 prettier-vscode|esb|9.10.4 copilot|Git|1.73.8685 remotehub|Git|0.50.0 vscode-docker|ms-|1.23.3 isort|ms-|2022.8.0 python|ms-|2023.3.10411009 vscode-pylance|ms-|2023.2.20 remote-containers|ms-|0.275.1 remote-ssh|ms-|0.96.0 remote-ssh-edit|ms-|0.84.0 remote-wsl|ms-|0.75.2 vscode-remote-extensionpack|ms-|0.23.0 azure-repos|ms-|0.26.0 remote-explorer|ms-|0.2.0 remote-repositories|ms-|0.28.0 remote-server|ms-|1.0.0 vsliveshare|ms-|1.0.5828 rust-analyzer|rus|0.3.1402 code-spell-checker|str|2.16.0
A/B Experiments ``` vsliv368cf:30146710 vsreu685:30147344 python383:30185418 vspor879:30202332 vspor708:30202333 vspor363:30204092 vstes627cf:30244335 vslsvsres303:30308271 pythonvspyl392:30443607 vserr242cf:30382550 pythontb:30283811 vsjup518:30340749 pythonptprofiler:30281270 vsdfh931:30280409 vshan820:30294714 vstes263:30335439 vscorecescf:30445987 pythondataviewer:30285071 vscod805cf:30301675 binariesv615:30325510 bridge0708:30335490 bridge0723:30353136 cmake_vspar411:30581797 vsaa593cf:30376535 pythonvs932:30410667 cppdebug:30492333 vsclangdf:30486550 c4g48928:30535728 dsvsc012cf:30540253 azure-dev_surveyone:30548225 vscccc:30610679 pyindex848:30577860 nodejswelcome1:30587005 282f8724:30602487 89544117:30613380 pythonsymbol12cf:30657549 a9j8j154:30646983 vscodedisable:30660115 ```
mjbvz commented 1 year ago

@karthiknadig Have you tried putting together a minimal example to prove this is a VS Code issue? If the extensions are well behaved, the actions will be run sequentially

karthiknadig commented 1 year ago

I tested it out. They both get version 1 of the document. Both get the same version:

This is Ruff image

This is isort image

In this scenario, both the extensions register the Organize Import capability via the LSP.

mjbvz commented 1 year ago

@karthiknadig Try creating a minimal example extension to figure out what the root cause is and provide easier steps to reproduce it. You can use https://github.com/microsoft/vscode-extension-samples/tree/main/code-actions-sample as a starting point

karthiknadig commented 1 year ago

@mjbvz I just wanted to clarify that this is a LSP scenario not a case where we use registerCodeActionsProvider API directly. Both isort and ruff extensions are thin wrappers around LSP servers running the tools. So, the only thing that happens in TS in creating the LS client and starting the LS.

I have added detailed logs. If things were working as you say, then there should have been a textDocument/didChange event before textDocument/codeAction request for one of the extensions. Since both extension receive the request at the same time, they both submit the edits for the file contents they see at that time.

Lets assume isort was called first, then after applying isorts edits VS Code generates the textDocument/didChange. We should have seen another code action request to get the fresh edits from Ruff after the change event. We don't see that, instead what we see is that edits of both isort and ruff from the first call are applied together. Applying them line that results in corrupted code. VS Code also generates two concurrent textDocument/didChange events, with NO code action request for fresh edits in between. This is why I believe this is a bug in VS Code.

time lines: image

LSP logs from isort ``` [Trace - 7:26:57 PM] Sending request 'textDocument/codeAction - (38)'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py" }, "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 1, "character": 0 } }, "context": { "diagnostics": [ { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "\"os\" is not accessed", "severity": 4, "tags": [ 1 ], "source": "Pylance" }, { "range": { "start": { "line": 0, "character": 10 }, "end": { "line": 0, "character": 13 } }, "message": "\"sys\" is not accessed", "severity": 4, "tags": [ 1 ], "source": "Pylance" }, { "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 0, "character": 13 } }, "message": "Multiple imports on one line", "code": "E401", "severity": 2, "source": "Ruff" }, { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "`os` imported but unused", "code": "F401", "severity": 2, "tags": [ 1 ], "source": "Ruff" }, { "range": { "start": { "line": 0, "character": 10 }, "end": { "line": 0, "character": 13 } }, "message": "`sys` imported but unused", "code": "F401", "severity": 2, "tags": [ 1 ], "source": "Ruff" } ], "only": [ "source.organizeImports" ] } } [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "c:\\GIT\\differ\\.venv\\Scripts\\python.exe -m isort - --filename c:\\GIT\\differ\\something.py" } c:\GIT\differ\.venv\Scripts\python.exe -m isort - --filename c:\GIT\differ\something.py [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "CWD Linter: c:\\GIT\\differ" } CWD Linter: c:\GIT\differ [Trace - 7:26:57 PM] Received notification 'textDocument/publishDiagnostics'. Params: { "uri": "file:///c%3A/GIT/differ/something.py", "diagnostics": [] } [Trace - 7:26:57 PM] Received response 'textDocument/codeAction - (38)' in 14ms. Result: [ { "title": "isort: Organize Imports", "kind": "source.organizeImports", "diagnostics": [], "edit": { "documentChanges": [ { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 21 }, "edits": [ { "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 1, "character": 0 } }, "newText": "import os\r\nimport sys\r\n" } ] } ] }, "data": "file:///c%3A/GIT/differ/something.py" } ] [Trace - 7:26:57 PM] Sending notification 'textDocument/didChange'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 22 }, "contentChanges": [ { "range": { "start": { "line": 0, "character": 9 }, "end": { "line": 0, "character": 10 } }, "rangeLength": 1, "text": "\r\nimport " } ] } [Trace - 7:26:57 PM] Sending notification 'textDocument/didChange'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 23 }, "contentChanges": [ { "range": { "start": { "line": 1, "character": 0 }, "end": { "line": 1, "character": 0 } }, "rangeLength": 0, "text": "import sys\r\n" } ] } [Trace - 7:26:57 PM] Sending notification 'textDocument/didSave'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py" } } [Trace - 7:26:57 PM] Received notification 'textDocument/publishDiagnostics'. Params: { "uri": "file:///c%3A/GIT/differ/something.py", "diagnostics": [] } ```
LSP logs from ruff ``` [Trace - 7:26:57 PM] Sending request 'textDocument/codeAction - (41)'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py" }, "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 1, "character": 0 } }, "context": { "diagnostics": [ { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "\"os\" is not accessed", "severity": 4, "tags": [ 1 ], "source": "Pylance" }, { "range": { "start": { "line": 0, "character": 10 }, "end": { "line": 0, "character": 13 } }, "message": "\"sys\" is not accessed", "severity": 4, "tags": [ 1 ], "source": "Pylance" }, { "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 0, "character": 13 } }, "message": "Multiple imports on one line", "code": "E401", "severity": 2, "source": "Ruff" }, { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "`os` imported but unused", "data": { "content": "", "message": "Remove unused import", "location": { "row": 1, "column": 0 }, "end_location": { "row": 2, "column": 0 } }, "code": "F401", "severity": 2, "tags": [ 1 ], "source": "Ruff" }, { "range": { "start": { "line": 0, "character": 10 }, "end": { "line": 0, "character": 13 } }, "message": "`sys` imported but unused", "data": { "content": "", "message": "Remove unused import", "location": { "row": 1, "column": 0 }, "end_location": { "row": 2, "column": 0 } }, "code": "F401", "severity": 2, "tags": [ 1 ], "source": "Ruff" } ], "only": [ "source.organizeImports" ] } } [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Using bundled executable: c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe" } Using bundled executable: c:\Users\kanadig\.vscode\extensions\charliermarsh.ruff-2023.8.0-win32-x64\bundled\libs\bin\ruff.exe [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Running Ruff with: ['c:\\\\Users\\\\kanadig\\\\.vscode\\\\extensions\\\\charliermarsh.ruff-2023.8.0-win32-x64\\\\bundled\\\\libs\\\\bin\\\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--fix', '--extend-ignore', 'ALL', '--extend-select', 'I001', '--stdin-filename', 'c:\\\\GIT\\\\differ\\\\something.py']" } Running Ruff with: ['c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--fix', '--extend-ignore', 'ALL', '--extend-select', 'I001', '--stdin-filename', 'c:\\GIT\\differ\\something.py'] [Trace - 7:26:57 PM] Received response 'textDocument/codeAction - (41)' in 355ms. Result: [ { "title": "Ruff: Organize Imports", "kind": "source.organizeImports", "diagnostics": [], "edit": { "documentChanges": [ { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 21 }, "edits": [ { "range": { "start": { "line": 0, "character": 0 }, "end": { "line": 1, "character": 0 } }, "newText": "import os\r\nimport sys\r\n" } ] } ] }, "data": "file:///c%3A/GIT/differ/something.py" } ] [Trace - 7:26:57 PM] Sending notification 'textDocument/didChange'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 22 }, "contentChanges": [ { "range": { "start": { "line": 0, "character": 9 }, "end": { "line": 0, "character": 10 } }, "rangeLength": 1, "text": "\r\nimport " } ] } [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Using bundled executable: c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe" } Using bundled executable: c:\Users\kanadig\.vscode\extensions\charliermarsh.ruff-2023.8.0-win32-x64\bundled\libs\bin\ruff.exe [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Running Ruff with: ['c:\\\\Users\\\\kanadig\\\\.vscode\\\\extensions\\\\charliermarsh.ruff-2023.8.0-win32-x64\\\\bundled\\\\libs\\\\bin\\\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\\\GIT\\\\differ\\\\something.py']" } Running Ruff with: ['c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\GIT\\differ\\something.py'] [Trace - 7:26:57 PM] Sending notification 'textDocument/didChange'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py", "version": 23 }, "contentChanges": [ { "range": { "start": { "line": 1, "character": 0 }, "end": { "line": 1, "character": 0 } }, "rangeLength": 0, "text": "import sys\r\n" } ] } [Trace - 7:26:57 PM] Sending notification 'textDocument/didSave'. Params: { "textDocument": { "uri": "file:///c%3A/GIT/differ/something.py" } } [Trace - 7:26:57 PM] Received notification 'textDocument/publishDiagnostics'. Params: { "uri": "file:///c%3A/GIT/differ/something.py", "diagnostics": [ { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "`os` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `os`", "location": { "row": 1, "column": 0 }, "end_location": { "row": 2, "column": 0 } } }, { "range": { "start": { "line": 1, "character": 7 }, "end": { "line": 1, "character": 10 } }, "message": "`sys` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `sys`", "location": { "row": 2, "column": 0 }, "end_location": { "row": 3, "column": 0 } } } ] } [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Using bundled executable: c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe" } Using bundled executable: c:\Users\kanadig\.vscode\extensions\charliermarsh.ruff-2023.8.0-win32-x64\bundled\libs\bin\ruff.exe [Trace - 7:26:57 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Running Ruff with: ['c:\\\\Users\\\\kanadig\\\\.vscode\\\\extensions\\\\charliermarsh.ruff-2023.8.0-win32-x64\\\\bundled\\\\libs\\\\bin\\\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\\\GIT\\\\differ\\\\something.py']" } Running Ruff with: ['c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\GIT\\differ\\something.py'] [Trace - 7:26:58 PM] Received notification 'textDocument/publishDiagnostics'. Params: { "uri": "file:///c%3A/GIT/differ/something.py", "diagnostics": [ { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "`os` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `os`", "location": { "row": 1, "column": 0 }, "end_location": { "row": 2, "column": 0 } } }, { "range": { "start": { "line": 2, "character": 7 }, "end": { "line": 2, "character": 10 } }, "message": "Redefinition of unused `sys` from line 2", "severity": 2, "code": "F811", "source": "Ruff" }, { "range": { "start": { "line": 2, "character": 7 }, "end": { "line": 2, "character": 10 } }, "message": "`sys` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `sys`", "location": { "row": 3, "column": 0 }, "end_location": { "row": 4, "column": 0 } } } ] } [Trace - 7:26:58 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Using bundled executable: c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe" } Using bundled executable: c:\Users\kanadig\.vscode\extensions\charliermarsh.ruff-2023.8.0-win32-x64\bundled\libs\bin\ruff.exe [Trace - 7:26:58 PM] Received notification 'window/logMessage'. Params: { "type": 4, "message": "Running Ruff with: ['c:\\\\Users\\\\kanadig\\\\.vscode\\\\extensions\\\\charliermarsh.ruff-2023.8.0-win32-x64\\\\bundled\\\\libs\\\\bin\\\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\\\GIT\\\\differ\\\\something.py']" } Running Ruff with: ['c:\\Users\\kanadig\\.vscode\\extensions\\charliermarsh.ruff-2023.8.0-win32-x64\\bundled\\libs\\bin\\ruff.exe', '--no-cache', '--no-fix', '--quiet', '--format', 'json', '-', '--stdin-filename', 'c:\\GIT\\differ\\something.py'] [Trace - 7:26:58 PM] Received notification 'textDocument/publishDiagnostics'. Params: { "uri": "file:///c%3A/GIT/differ/something.py", "diagnostics": [ { "range": { "start": { "line": 0, "character": 7 }, "end": { "line": 0, "character": 9 } }, "message": "`os` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `os`", "location": { "row": 1, "column": 0 }, "end_location": { "row": 2, "column": 0 } } }, { "range": { "start": { "line": 2, "character": 7 }, "end": { "line": 2, "character": 10 } }, "message": "Redefinition of unused `sys` from line 2", "severity": 2, "code": "F811", "source": "Ruff" }, { "range": { "start": { "line": 2, "character": 7 }, "end": { "line": 2, "character": 10 } }, "message": "`sys` imported but unused", "severity": 2, "code": "F401", "source": "Ruff", "tags": [ 1 ], "data": { "content": "", "message": "Remove unused import: `sys`", "location": { "row": 3, "column": 0 }, "end_location": { "row": 4, "column": 0 } } } ] } ```
mjbvz commented 1 year ago

It will be much easier to understand the problem with a minimal, self-contained example . Can you please try putting one together using our extension sample code: https://github.com/microsoft/vscode-extension-samples/tree/main/code-actions-sample

karthiknadig commented 1 year ago

I have created a repo https://github.com/karthiknadig/organize1

Repro steps:

  1. Build and debug the extension in https://github.com/karthiknadig/organize1
  2. Set a breakpoint inside processText in sortImport.ts
  3. Create a folder with .vscode/settings.json and a myscript.py.
  4. Use the following contents for the settings.json:
    {
    "editor.formatOnSave": false,
    "editor.codeActionsOnSave": {
        "source.fixAll": false,
        "source.organizeImports": true
    },
    }
  5. Use the following myscript.py:
    import os,sys

Actual: processText gets called twice with the same content.

Expected: First call to processText should be import os,sys Second call to processText should be import os\r\nimport sys\r\n\r\n

This is how the edits get applied in the cascade: image

image

image

VSCodeTriageBot commented 1 year ago

This issue has been closed automatically because it needs more information and has not had recent activity. See also our issue reporting guidelines.

Happy Coding!

crucialfelix commented 1 year ago

I experienced this too: https://github.com/microsoft/vscode-black-formatter/issues/220

When both isort and ruff organize imports then somehow the last lines at the bottom of the file get duplicated. That may be black doing it, I'm still not sure.

jgmarcel commented 1 year ago

I am also affected by this problem (with black and isort).

xhrnca00 commented 1 year ago

I just spent over an hour trying to find out why the file would change on every save. I have isort set to leave two blank lines after formatting. So on one Sort Imports run, isort would do nothing and Ruff would remove one line. On another run, isort would add a line and Ruff would do nothing (this also proves that both formatters get the same file). The only way to make this go away was to disable organised imports. Then I found out (by scrubbing through isort release notes) that Ruff formats imports as well (I did not know that initially, as it is enabled by default).

There is NO indication whatsoever that multiple handlers of source.organizeImports are registered. I think this is a UI/UX thing, there should be a way to configure which one is run (just like with formatters).

alexclaydon commented 9 months ago

This is such a pernicious bug. Just found a bunch of weeks-old commits in our codebase with final line repeated. Having read this issue a couple of months ago, I had promptly disabled isort - a Microsoft plugin - but was surprised to see upon checking today that it had apparently re-enabled itself. For anyone finding their way here in future, simply disabling isort won't be enough.

alexcouper commented 4 months ago

Just to say I'm experiencing this (ruff and isort)

I have gone round the issue by disabling the ruff sorter using "ruff.organizeImports": false in the workspace settings