Tooltitude blocks file saving action intermittently

tigerinus commented 8 months ago

Tooltitude Version: 0.59.0

OS Version: Ubuntu 23.10

VS Code Version:

Version: 1.86.2
Commit: 903b1e9d8990623e3d7da1df3d33db3e42d80eda
Date: 2024-02-13T19:41:37.860Z
Electron: 27.2.3
ElectronBuildId: 26908389
Chromium: 118.0.5993.159
Node.js: 18.17.1
V8: 11.8.172.18-electron.0
OS: Linux x64 6.5.0-17-generic

Go Version: go version go1.21.7 linux/amd64

Code Repository (if open source): https://github.com/IceWhaleTech/CasaOS-AppManagement

What did you try to do?

Try to save a changed .go file.

Is there anything interesting in the tooltitude output channel? (should be open if you are reporting error from within VS Code)

Not really - all INFO level messages.

Steps to reproduce

Step 1: Open the Golang project.
Step 2: Make some changes to some .go file, and save

Then saving is blocked for few minutes by a popup:

Workaround: Kill VSCode and reload window.

output:

2024-02-21T01:48:36.024309Z  INFO provide_impl_intfc_overlays: close time.busy=874ns time.idle=2.25µs
2024-02-21T01:48:36.224174Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}: new
2024-02-21T01:48:36.224177Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}: new
2024-02-21T01:48:36.224210Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}: new
2024-02-21T01:48:36.224307Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}:broken_refs_checker: new
2024-02-21T01:48:36.224313Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}:broken_refs_checker: close time.busy=1.97µs time.idle=3.38µs
2024-02-21T01:48:36.224315Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}:broken_refs_checker: new
2024-02-21T01:48:36.224321Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}:dataflow_checker: new
2024-02-21T01:48:36.224320Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}:broken_refs_checker: close time.busy=972ns time.idle=4.26µs
2024-02-21T01:48:36.224329Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}:dataflow_checker: new
2024-02-21T01:48:36.224339Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}:dataflow_checker: close time.busy=16.0µs time.idle=2.05µs
2024-02-21T01:48:36.224343Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}:dataflow_checker: close time.busy=12.1µs time.idle=1.47µs
2024-02-21T01:48:36.224350Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/domain_service.go"}: close time.busy=163µs time.idle=11.1µs
2024-02-21T01:48:36.224353Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/installation.go"}: close time.busy=136µs time.idle=7.11µs
2024-02-21T01:48:36.224358Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}:broken_refs_checker: new
2024-02-21T01:48:36.224363Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}:broken_refs_checker: close time.busy=687ns time.idle=3.78µs
2024-02-21T01:48:36.224370Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}:dataflow_checker: new
2024-02-21T01:48:36.224400Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}:dataflow_checker: close time.busy=28.2µs time.idle=1.51µs
2024-02-21T01:48:36.224409Z  INFO run_check{doc="file:///home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go"}: close time.busy=224µs time.idle=12.6µs
2024-02-21T01:48:36.225417Z  INFO lsp_response{id="209"}: new
2024-02-21T01:48:36.225441Z  INFO lsp_response{id="209"}: close time.busy=13.2µs time.idle=11.4µs
2024-02-21T01:48:36.226339Z  INFO lsp_response{id="210"}: new
2024-02-21T01:48:36.226354Z  INFO lsp_response{id="210"}: close time.busy=5.45µs time.idle=10.5µs
2024-02-21T01:48:36.226941Z  INFO lsp_response{id="211"}: new
2024-02-21T01:48:36.226962Z  INFO lsp_response{id="211"}: close time.busy=3.52µs time.idle=17.5µs
2024-02-21T01:48:36.374536Z  INFO lsp_notification{method="workspace/didChangeWatchedFiles"}: new
2024-02-21T01:48:36.374605Z  INFO lsp_notification{method="workspace/didChangeWatchedFiles"}: close time.busy=43.6µs time.idle=28.4µs
2024-02-21T01:48:36.374723Z  INFO on_did_change_watched_files: DidChangeWatchedFilesParams {
    changes: [
        FileEvent {
            uri: Url {
                scheme: "file",
                cannot_be_a_base: false,
                username: "",
                password: None,
                host: None,
                port: None,
                path: "/home/tiger/dev/IceWhaleTech/ZimaOS-VirtManagement/service/service.go",
                query: None,
                fragment: None,
            },
            typ: Changed,
        },
    ],
}
2024-02-21T01:51:37.220600Z  INFO lsp_request{method="textDocument/codeAction" id="276"}: new
2024-02-21T01:51:37.220641Z  INFO lsp_request{method="textDocument/codeAction" id="276"}: close time.busy=26.9µs time.idle=15.8µs
2024-02-21T01:51:37.220655Z  INFO lsp_request{method="textDocument/inlayHint" id="277"}: new
2024-02-21T01:51:37.220664Z  INFO lsp_request{method="textDocument/inlayHint" id="277"}: close time.busy=5.75µs time.idle=2.89µs
2024-02-21T01:51:37.220669Z  INFO lsp_request{method="textDocument/codeAction" id="278"}: new
2024-02-21T01:51:37.220677Z  INFO lsp_request{method="textDocument/codeAction" id="278"}: close time.busy=5.49µs time.idle=2.74µs
2024-02-21T01:51:37.220686Z  INFO lsp_cancel_request{id="276"}: new
2024-02-21T01:51:37.220688Z  INFO lsp_cancel_request{id="276"}: close time.busy=252ns time.idle=2.50µs
2024-02-21T01:51:37.220695Z  INFO lsp_request{method="textDocument/codeLens" id="279"}: new
2024-02-21T01:51:37.220707Z  INFO lsp_request{method="textDocument/codeLens" id="279"}: close time.busy=9.56µs time.idle=2.53µs
2024-02-21T01:51:37.220712Z  INFO lsp_cancel_request{id="278"}: new
2024-02-21T01:51:37.220715Z  INFO lsp_cancel_request{id="278"}: close time.busy=236ns time.idle=2.44µs
2024-02-21T01:51:37.220720Z  INFO lsp_notification{method="textDocument/willSave"}: new
2024-02-21T01:51:37.220728Z  INFO lsp_notification{method="textDocument/willSave"}: close time.busy=6.45µs time.idle=2.37µs
2024-02-21T01:51:37.220734Z  INFO lsp_request{method="textDocument/codeAction" id="280"}: new
2024-02-21T01:51:37.220740Z  INFO lsp_request{method="textDocument/codeAction" id="280"}: close time.busy=4.34µs time.idle=2.25µs
2024-02-21T01:51:37.220746Z  INFO lsp_request{method="textDocument/codeAction" id="281"}: new
2024-02-21T01:51:37.220754Z  INFO lsp_request{method="textDocument/codeAction" id="281"}: close time.busy=5.24µs time.idle=2.41µs
2024-02-21T01:51:37.220761Z  INFO lsp_request{method="textDocument/codeAction" id="282"}: new
2024-02-21T01:51:37.220758Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.220770Z  INFO lsp_request{method="textDocument/codeAction" id="282"}: close time.busy=4.00µs time.idle=5.87µs
2024-02-21T01:51:37.220776Z  INFO lsp_cancel_request{id="280"}: new
2024-02-21T01:51:37.220780Z  INFO lsp_cancel_request{id="280"}: close time.busy=586ns time.idle=2.86µs
2024-02-21T01:51:37.220786Z  INFO provide_inlay_hints: close time.busy=14.4µs time.idle=13.9µs
2024-02-21T01:51:37.220791Z  INFO lsp_cancel_request{id="277"}: new
2024-02-21T01:51:37.220796Z  INFO lsp_cancel_request{id="277"}: close time.busy=698ns time.idle=4.56µs
2024-02-21T01:51:37.220803Z  INFO lsp_request{method="textDocument/inlayHint" id="283"}: new
2024-02-21T01:51:37.220809Z  INFO lsp_request{method="textDocument/inlayHint" id="283"}: close time.busy=4.24µs time.idle=2.26µs
2024-02-21T01:51:37.220816Z  INFO lsp_cancel_request{id="283"}: new
2024-02-21T01:51:37.220819Z  INFO lsp_cancel_request{id="283"}: close time.busy=234ns time.idle=2.36µs
2024-02-21T01:51:37.220886Z  INFO provide_run_debug_main_overlays: new
2024-02-21T01:51:37.220895Z  INFO provide_run_debug_main_overlays: close time.busy=1.03µs time.idle=8.51µs
2024-02-21T01:51:37.220898Z  INFO provide_test_overlays: new
2024-02-21T01:51:37.220900Z  INFO provide_test_overlays: close time.busy=455ns time.idle=1.41µs
2024-02-21T01:51:37.220903Z  INFO provide_debug_table_test_overlays: new
2024-02-21T01:51:37.220906Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.220913Z  INFO provide_debug_table_test_overlays: close time.busy=8.89µs time.idle=1.64µs
2024-02-21T01:51:37.220916Z  INFO provide_refs_overlays: new
2024-02-21T01:51:37.220918Z  INFO provide_inlay_hints: close time.busy=8.44µs time.idle=4.43µs
2024-02-21T01:51:37.220923Z  INFO lsp_request{method="textDocument/inlayHint" id="284"}: new
2024-02-21T01:51:37.220940Z  INFO lsp_request{method="textDocument/inlayHint" id="284"}: close time.busy=10.0µs time.idle=7.55µs
2024-02-21T01:51:37.220943Z  INFO provide_refs_overlays: 4 packages to scan
2024-02-21T01:51:37.220949Z  INFO lsp_cancel_request{id="284"}: new
2024-02-21T01:51:37.220953Z  INFO lsp_cancel_request{id="284"}: close time.busy=350ns time.idle=3.32µs
2024-02-21T01:51:37.220961Z  INFO lsp_request{method="textDocument/inlayHint" id="285"}: new
2024-02-21T01:51:37.220968Z  INFO lsp_request{method="textDocument/inlayHint" id="285"}: close time.busy=4.88µs time.idle=2.81µs
2024-02-21T01:51:37.220973Z  INFO lsp_cancel_request{id="285"}: new
2024-02-21T01:51:37.220976Z  INFO lsp_cancel_request{id="285"}: close time.busy=224ns time.idle=2.43µs
2024-02-21T01:51:37.220981Z  INFO lsp_request{method="textDocument/inlayHint" id="286"}: new
2024-02-21T01:51:37.220988Z  INFO lsp_request{method="textDocument/inlayHint" id="286"}: close time.busy=3.80µs time.idle=2.53µs
2024-02-21T01:51:37.220991Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.220993Z  INFO lsp_cancel_request{id="286"}: new
2024-02-21T01:51:37.221014Z  INFO lsp_cancel_request{id="286"}: close time.busy=335ns time.idle=20.9µs
2024-02-21T01:51:37.221019Z  INFO provide_inlay_hints: close time.busy=11.4µs time.idle=17.4µs
2024-02-21T01:51:37.221025Z  INFO lsp_request{method="textDocument/inlayHint" id="287"}: new
2024-02-21T01:51:37.221025Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221032Z  INFO lsp_request{method="textDocument/inlayHint" id="287"}: close time.busy=4.53µs time.idle=3.13µs
2024-02-21T01:51:37.221035Z  INFO provide_inlay_hints: close time.busy=6.39µs time.idle=3.97µs
2024-02-21T01:51:37.221041Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221049Z  INFO lsp_cancel_request{id="287"}: new
2024-02-21T01:51:37.221049Z  INFO provide_inlay_hints: close time.busy=6.07µs time.idle=2.68µs
2024-02-21T01:51:37.221052Z  INFO lsp_cancel_request{id="287"}: close time.busy=229ns time.idle=3.02µs
2024-02-21T01:51:37.221054Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221062Z  INFO lsp_request{method="textDocument/inlayHint" id="288"}: new
2024-02-21T01:51:37.221062Z  INFO provide_inlay_hints: close time.busy=5.49µs time.idle=3.10µs
2024-02-21T01:51:37.221081Z  INFO lsp_request{method="textDocument/inlayHint" id="288"}: close time.busy=15.8µs time.idle=2.84µs
2024-02-21T01:51:37.221089Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221099Z  INFO provide_inlay_hints: close time.busy=5.96µs time.idle=3.97µs
2024-02-21T01:51:37.221104Z  INFO lsp_cancel_request{id="288"}: new
2024-02-21T01:51:37.221107Z  INFO lsp_cancel_request{id="288"}: close time.busy=287ns time.idle=3.27µs
2024-02-21T01:51:37.221112Z  INFO lsp_request{method="textDocument/inlayHint" id="289"}: new
2024-02-21T01:51:37.221121Z  INFO lsp_request{method="textDocument/inlayHint" id="289"}: close time.busy=5.82µs time.idle=2.51µs
2024-02-21T01:51:37.221126Z  INFO lsp_cancel_request{id="289"}: new
2024-02-21T01:51:37.221128Z  INFO lsp_cancel_request{id="289"}: close time.busy=158ns time.idle=2.33µs
2024-02-21T01:51:37.221136Z  INFO lsp_request{method="textDocument/inlayHint" id="290"}: new
2024-02-21T01:51:37.221142Z  INFO lsp_request{method="textDocument/inlayHint" id="290"}: close time.busy=3.42µs time.idle=2.41µs
2024-02-21T01:51:37.221147Z  INFO lsp_cancel_request{id="290"}: new
2024-02-21T01:51:37.221150Z  INFO lsp_cancel_request{id="290"}: close time.busy=194ns time.idle=2.49µs
2024-02-21T01:51:37.221190Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221206Z  INFO provide_inlay_hints: close time.busy=9.79µs time.idle=7.23µs
2024-02-21T01:51:37.221212Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221220Z  INFO provide_inlay_hints: close time.busy=5.59µs time.idle=2.61µs
2024-02-21T01:51:37.221229Z  INFO lsp_request{method="textDocument/inlayHint" id="291"}: new
2024-02-21T01:51:37.221244Z  INFO lsp_request{method="textDocument/inlayHint" id="291"}: close time.busy=8.59µs time.idle=7.28µs
2024-02-21T01:51:37.221255Z  INFO lsp_cancel_request{id="291"}: new
2024-02-21T01:51:37.221259Z  INFO lsp_cancel_request{id="291"}: close time.busy=292ns time.idle=3.08µs
2024-02-21T01:51:37.221265Z  INFO lsp_request{method="textDocument/inlayHint" id="292"}: new
2024-02-21T01:51:37.221272Z  INFO lsp_request{method="textDocument/inlayHint" id="292"}: close time.busy=3.88µs time.idle=2.99µs
2024-02-21T01:51:37.221278Z  INFO lsp_cancel_request{id="292"}: new
2024-02-21T01:51:37.221280Z  INFO lsp_cancel_request{id="292"}: close time.busy=251ns time.idle=2.45µs
2024-02-21T01:51:37.221279Z  INFO provide_refs_overlays: close time.busy=361µs time.idle=2.21µs
2024-02-21T01:51:37.221286Z  INFO lsp_request{method="textDocument/inlayHint" id="293"}: new
2024-02-21T01:51:37.221291Z  INFO provide_intfc_impls_overlays: new
2024-02-21T01:51:37.221293Z  INFO lsp_request{method="textDocument/inlayHint" id="293"}: close time.busy=3.35µs time.idle=3.33µs
2024-02-21T01:51:37.221298Z  INFO lsp_cancel_request{id="293"}: new
2024-02-21T01:51:37.221301Z  INFO lsp_cancel_request{id="293"}: close time.busy=237ns time.idle=2.60µs
2024-02-21T01:51:37.221306Z  INFO lsp_request{method="textDocument/inlayHint" id="294"}: new
2024-02-21T01:51:37.221307Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221313Z  INFO lsp_request{method="textDocument/inlayHint" id="294"}: close time.busy=4.58µs time.idle=2.54µs
2024-02-21T01:51:37.221319Z  INFO lsp_cancel_request{id="294"}: new
2024-02-21T01:51:37.221321Z  INFO lsp_cancel_request{id="294"}: close time.busy=197ns time.idle=2.54µs
2024-02-21T01:51:37.221325Z  INFO provide_inlay_hints: close time.busy=10.8µs time.idle=7.40µs
2024-02-21T01:51:37.221328Z  INFO lsp_request{method="textDocument/inlayHint" id="295"}: new
2024-02-21T01:51:37.221331Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221336Z  INFO lsp_request{method="textDocument/inlayHint" id="295"}: close time.busy=4.27µs time.idle=2.82µs
2024-02-21T01:51:37.221342Z  INFO provide_inlay_hints: close time.busy=8.20µs time.idle=2.80µs
2024-02-21T01:51:37.221344Z  INFO lsp_cancel_request{id="295"}: new
2024-02-21T01:51:37.221346Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221347Z  INFO lsp_cancel_request{id="295"}: close time.busy=171ns time.idle=3.42µs
2024-02-21T01:51:37.221355Z  INFO provide_inlay_hints: close time.busy=5.66µs time.idle=2.93µs
2024-02-21T01:51:37.221359Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221362Z  INFO lsp_request{method="textDocument/inlayHint" id="296"}: new
2024-02-21T01:51:37.221368Z  INFO provide_inlay_hints: close time.busy=7.05µs time.idle=2.43µs
2024-02-21T01:51:37.221370Z  INFO lsp_request{method="textDocument/inlayHint" id="296"}: close time.busy=5.13µs time.idle=2.79µs
2024-02-21T01:51:37.221373Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221377Z  INFO lsp_cancel_request{id="296"}: new
2024-02-21T01:51:37.221380Z  INFO provide_inlay_hints: close time.busy=5.03µs time.idle=2.71µs
2024-02-21T01:51:37.221381Z  INFO lsp_cancel_request{id="296"}: close time.busy=253ns time.idle=3.04µs
2024-02-21T01:51:37.221384Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221395Z  INFO provide_inlay_hints: close time.busy=7.80µs time.idle=2.64µs
2024-02-21T01:51:37.221399Z  INFO provide_intfc_impls_overlays: close time.busy=105µs time.idle=3.61µs
2024-02-21T01:51:37.221402Z  INFO lsp_request{method="textDocument/inlayHint" id="297"}: new
2024-02-21T01:51:37.221405Z  INFO provide_method_to_intfcs_overlays: new
2024-02-21T01:51:37.221411Z  INFO lsp_request{method="textDocument/inlayHint" id="297"}: close time.busy=4.92µs time.idle=4.29µs
2024-02-21T01:51:37.221422Z  INFO lsp_cancel_request{id="297"}: new
2024-02-21T01:51:37.221425Z  INFO lsp_cancel_request{id="297"}: close time.busy=257ns time.idle=2.91µs
2024-02-21T01:51:37.221440Z  INFO lsp_request{method="textDocument/inlayHint" id="298"}: new
2024-02-21T01:51:37.221446Z  INFO lsp_request{method="textDocument/inlayHint" id="298"}: close time.busy=3.65µs time.idle=2.98µs
2024-02-21T01:51:37.221472Z  INFO provide_method_to_intfcs_overlays: close time.busy=63.6µs time.idle=3.26µs
2024-02-21T01:51:37.221476Z  INFO provide_ty_intfcs_overlays: new
2024-02-21T01:51:37.221485Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221502Z  INFO provide_inlay_hints: close time.busy=9.91µs time.idle=7.24µs
2024-02-21T01:51:37.221507Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221516Z  INFO provide_inlay_hints: close time.busy=5.49µs time.idle=3.40µs
2024-02-21T01:51:37.221532Z  INFO lsp_cancel_request{id="298"}: new
2024-02-21T01:51:37.221537Z  INFO provide_ty_intfcs_overlays: close time.busy=57.9µs time.idle=2.66µs
2024-02-21T01:51:37.221542Z  INFO provide_ty_methods_overlays: new
2024-02-21T01:51:37.221539Z  INFO lsp_cancel_request{id="298"}: close time.busy=643ns time.idle=7.54µs
2024-02-21T01:51:37.221545Z  INFO provide_ty_methods_overlays: close time.busy=1.20µs time.idle=2.31µs
2024-02-21T01:51:37.221550Z  INFO provide_show_unused_overlays: new
2024-02-21T01:51:37.221552Z  INFO lsp_request{method="textDocument/inlayHint" id="299"}: new
2024-02-21T01:51:37.221554Z  INFO provide_show_unused_overlays: close time.busy=1.98µs time.idle=2.59µs
2024-02-21T01:51:37.221557Z  INFO provide_impl_intfc_overlays: new
2024-02-21T01:51:37.221560Z  INFO provide_impl_intfc_overlays: close time.busy=921ns time.idle=2.17µs
2024-02-21T01:51:37.221563Z  INFO lsp_request{method="textDocument/inlayHint" id="299"}: close time.busy=7.40µs time.idle=3.26µs
2024-02-21T01:51:37.221566Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221569Z  INFO lsp_cancel_request{id="299"}: new
2024-02-21T01:51:37.221572Z  INFO lsp_cancel_request{id="299"}: close time.busy=322ns time.idle=2.88µs
2024-02-21T01:51:37.221575Z  INFO provide_inlay_hints: close time.busy=5.41µs time.idle=3.81µs
2024-02-21T01:51:37.221578Z  INFO lsp_request{method="textDocument/inlayHint" id="300"}: new
2024-02-21T01:51:37.221591Z  INFO lsp_request{method="textDocument/inlayHint" id="300"}: close time.busy=5.24µs time.idle=8.23µs
2024-02-21T01:51:37.221594Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221597Z  INFO lsp_cancel_request{id="300"}: new
2024-02-21T01:51:37.221600Z  INFO lsp_cancel_request{id="300"}: close time.busy=269ns time.idle=2.92µs
2024-02-21T01:51:37.221603Z  INFO provide_inlay_hints: close time.busy=5.02µs time.idle=3.33µs
2024-02-21T01:51:37.221606Z  INFO lsp_request{method="textDocument/inlayHint" id="301"}: new
2024-02-21T01:51:37.221617Z  INFO lsp_request{method="textDocument/inlayHint" id="301"}: close time.busy=8.04µs time.idle=3.06µs
2024-02-21T01:51:37.221620Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221623Z  INFO lsp_cancel_request{id="301"}: new
2024-02-21T01:51:37.221626Z  INFO lsp_cancel_request{id="301"}: close time.busy=200ns time.idle=2.87µs
2024-02-21T01:51:37.221628Z  INFO provide_inlay_hints: close time.busy=5.33µs time.idle=3.21µs
2024-02-21T01:51:37.221631Z  INFO lsp_request{method="textDocument/inlayHint" id="302"}: new
2024-02-21T01:51:37.221638Z  INFO lsp_request{method="textDocument/inlayHint" id="302"}: close time.busy=4.99µs time.idle=2.60µs
2024-02-21T01:51:37.221641Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221659Z  INFO provide_inlay_hints: close time.busy=14.3µs time.idle=3.52µs
2024-02-21T01:51:37.221677Z  INFO lsp_cancel_request{id="302"}: new
2024-02-21T01:51:37.221680Z  INFO lsp_cancel_request{id="302"}: close time.busy=285ns time.idle=3.54µs
2024-02-21T01:51:37.221687Z  INFO lsp_request{method="textDocument/inlayHint" id="303"}: new
2024-02-21T01:51:37.221694Z  INFO lsp_request{method="textDocument/inlayHint" id="303"}: close time.busy=5.11µs time.idle=2.58µs
2024-02-21T01:51:37.221698Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221701Z  INFO lsp_cancel_request{id="303"}: new
2024-02-21T01:51:37.221704Z  INFO lsp_cancel_request{id="303"}: close time.busy=271ns time.idle=2.71µs
2024-02-21T01:51:37.221707Z  INFO provide_inlay_hints: close time.busy=6.36µs time.idle=3.22µs
2024-02-21T01:51:37.221708Z  INFO lsp_request{method="textDocument/inlayHint" id="304"}: new
2024-02-21T01:51:37.221718Z  INFO lsp_request{method="textDocument/inlayHint" id="304"}: close time.busy=5.72µs time.idle=4.20µs
2024-02-21T01:51:37.221724Z  INFO lsp_cancel_request{id="304"}: new
2024-02-21T01:51:37.221724Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221727Z  INFO lsp_cancel_request{id="304"}: close time.busy=198ns time.idle=2.62µs
2024-02-21T01:51:37.221734Z  INFO lsp_request{method="textDocument/inlayHint" id="305"}: new
2024-02-21T01:51:37.221736Z  INFO provide_inlay_hints: close time.busy=7.16µs time.idle=4.31µs
2024-02-21T01:51:37.221740Z  INFO provide_inlay_hints: new
2024-02-21T01:51:37.221740Z  INFO lsp_request{method="textDocument/inlayHint" id="305"}: close time.busy=4.13µs time.idle=2.56µs
2024-02-21T01:51:37.221747Z  INFO provide_inlay_hints: close time.busy=4.78µs time.idle=2.32µs

tooltitude-support commented 8 months ago

@tigerinus Thank you for your feedback. From the error message it looks like Tooltitude tries to provide the list of code actions, and hangs in this state. May I ask you to share the editor position which you have?

tigerinus commented 8 months ago

@tigerinus Thank you for your feedback. From the error message it looks like Tooltitude tries to provide the list of code actions, and hangs in this state. May I ask you to share the editor position which you have?

I'm sorry - What do you mean by editor position?

tooltitude-support commented 8 months ago

@tigerinus By editor location I mean the location of the cursor in the file, or selection state at this point.

tooltitude-support commented 8 months ago

@tigerinus Also, if you could join our discord, https://discord.com/invite/f9MHBXsVwr it would be much easier to discuss the problem there via personal messages.

tooltitude-support commented 8 months ago

It might be related to this previously reported issue: https://github.com/tooltitude/support/issues/31

tooltitude-support commented 8 months ago

@tigerinus 0.60 is out with additional diagnostics which should help us to resolve this issue.

tooltitude-support commented 8 months ago

@tigerinus After some investigation, it seems that vscode, might submit a large number of lsp requests, and cancel them. We might be spending time handling all these cancelled requests. Since 0.60.2 we correctly handle cancelled requests, and it should help.

Please update to the latest version, and let us know if you have it again.

tooltitude-support commented 8 months ago

@tigerinus If you have this again, it would be very helpful if you:

Find the tooltitude process with ps -A | grep tooltitude
Run pstack PID (on mac you could run sample PID), and send us the stacktrace

P.S. You need to install pstack on ubuntu since it's not included by default with sudo apt install -y pstack

tigerinus commented 8 months ago

I haven't seen this issue again since upgraded to latest version.

How about close this first. I will reopen when it happens again.

tooltitude-support commented 8 months ago

@tigerinus I would keep it open for some time in case someone else experiences this, and then close.

tooltitude-support commented 8 months ago

There were no reports of it for some time, so I am closing it.

tigerinus commented 8 months ago

@tigerinus I would keep it open for some time in case someone else experiences this, and then close.

The infinite wait no long happens in the latest version.

But the wait time is still somewhat lengthy (around 10 seconds) for each save (when it starts to happen)

tooltitude-support commented 8 months ago

@tigerinus Thanks, that's very interesting! Reopening the issue.

tooltitude-support commented 8 months ago

Please disregard my previous comments after I reopened the issue. I will think what might be causing this.

What was changed between the version where you had a hang and now is that we handle request cancellation for not yet started requests instead of running them to completion, and ignoring cancellation requests. But why are they get accumulated in the first place?

tooltitude-support commented 8 months ago

@tigerinus Thanks to additional diagnostics we found one place where we had lags of >100ms, which could escalate if you have a lot of such requests in parallel, and other processes consuming CPU. The fix will be available in 0.63.0 likely closer to Friday.

Please let us know if you have any more problems like this.

P.S. We will continue to investigate since we now have a better ideas which other requests might lead to the same symptoms.

tooltitude-support commented 8 months ago

0.63.0 is out with some improvements and additional diagnostics (we have more hypotheses of what else might be slowing stuff down). Please let us know if you have this issue again. (you will likely have it, but the lag should be smaller)

tigerinus commented 8 months ago

Sadly, the long wait happens again with latest version - This time it's around 30 seconds.

tooltitude-support commented 8 months ago

@tigerinus Thanks for the update. It's interesting.

May I ask you to do the following. If you have this again: run 'sudo cat /proc/$(pgrep tooltitude)/stack' on the machine where tooltitude is running.

Note:

$(pgrep tooltitude) finds the PID of tooltitude
cat prints the stacktrace from the /proc file system
on my machine it didn't work without sudo

This command will show us what the tooltitude process is doing which should help with understanding the reason of the hang.

tooltitude-support commented 7 months ago

After some investigation, here's my working hypothesis:

It looks like the hang happens when you invoke the code actions menu
It works in a separate thread, so you could use the extension, but something is running there
When you close the file, it waits for it to finish, but since it hanged it never finishes

To fix it, we need to understand why it hangs or works very slowly.

So, it would be really great if you could share if the following happened, and at which place:

You pressed Cmd+. or invoked the code actions menu via mouse
Nothing happens

(On our side, I will add more diagnostics to find out the reason and fix it)

tooltitude-support commented 7 months ago

The diagnostics show that the code action which seem to hang is apply De Morgan laws. Will investigate it further. Hopefully, we will fix it by the end of this week.

tooltitude-support commented 7 months ago

Ok. I found the reason and hang and reproduced it (put a caret on the first || in a == 1 || b == 1 || c == 1), and fixed. I started 0.66.3 build, which should be out in 10-30 minutes. Please, update to it, and let me know whether it helps.

tooltitude-support commented 7 months ago

@tigerinus How is it going with hangs? Did you experience them since upgrade to 0.66.3?

tigerinus commented 7 months ago

@tigerinus How is it going with hangs? Did you experience them since upgrade to 0.66.3?

I stepped away from Golang coding since last week, so I haven't got a chance to try the new version.

Why don't you just close this issue - if it happens again I will re-open.

tooltitude-support commented 7 months ago

@tigerinus Ok. Closing it now. Thanks a lot for your feedback. Don't hesitate to report problems if you encounter them, or ask for new features. We would be happy to see what we could do.

tooltitude / support

Tooltitude blocks file saving action intermittently #33