phpactor icon indicating copy to clipboard operation
phpactor copied to clipboard
verified publisher icon phpactor

Process killed after 5s after unknown text document error - using Zed

Open OliverBeckwith opened this issue 1 year ago • 11 comments

Context:

  • On a large Laravel + legacy codebase
  • Using Zed.

phpactor gets stuck "resolving code actions" after a while quickly moving around within a large project. Enabling logging surfaces that the lsp process is killed "because it lived longer than 5s", immediately after an unknown text document error (commonly for a file that isn't even php, such as a .env or other config file).

Image

Log:


[2025-02-20 15:09:04] phpactor.INFO: Listening on STDIO {"channel":"LSP"} []
[2025-02-20 15:09:04] phpactor.INFO: Starting service: diagnostics (Phpactor\LanguageServer\Service\DiagnosticsService) {"channel":"LSP"} []
[2025-02-20 15:09:04] phpactor.INFO: Starting service: indexer (Phpactor\Extension\LanguageServerIndexer\Handler\IndexerHandler) {"channel":"LSP"} []
[2025-02-20 15:09:09] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"workspace\/didChangeConfiguration","params":{"settings":[]}}): Exception [Phpactor\LanguageServer\Core\Handler\HandlerNotFound] Handler "workspace/didChangeConfiguration" not found, available handlers: "phpactor/debug/config", "phpactor/debug/workspace", "phpactor/status", "phpactor/service/start", "phpactor/service/stop", "phpactor/service/running", "workspace/executeCommand", "workspace/didChangeWatchedFiles", "textDocument/didOpen", "textDocument/didChange", "textDocument/didClose", "textDocument/didSave", "textDocument/willSave", "textDocument/willSaveWaitUntil", "phpactor/stats", "textDocument/codeAction", "textDocument/completion", "completionItem/resolve", "textDocument/signatureHelp", "textDocument/definition", "textDocument/typeDefinition", "textDocument/references", "textDocument/implementation", "textDocument/documentHighlight", "phpactor/indexer/reindex", "workspace/symbol", "textDocument/hover", "textDocument/documentSymbol", "textDocument/selectionRange", "textDocument/prepareRename", "textDocument/rename", "workspace/willRenameFiles" {"channel":"LSP"} []
[2025-02-20 15:09:15] phpactor.WARNING: The process was killed {"channel":"LSP"} []
[2025-02-20 15:09:15] phpactor.WARNING: Killed process "55160" ('/opt/homebrew/Cellar/php/8.4.3/bin/php' '/Users/ollie.beckwith/Library/Application Support/Zed/extensions/work/php/phpactor-2024.11.28.1/phpactor.phar' 'language-server:diagnostics' '--uri=file:///Users/ollie.beckwith/Documents/sites/project/app/Models/Order.php' '--config-extra={"worse_reflection.enable_context_location": false}') because it lived longer than 5s {"channel":"LSP"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Do not know how to goto definition of symbol type "<unknown>"" {"channel":"LSP-REF"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Word "App\Models\[" could not be resolved to a class" {"channel":"LSP-REF"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Could not locate any references to variable" {"channel":"LSP-REF"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Do not know how to goto definition of symbol type "<unknown>"" {"channel":"LSP-REF"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Word "App\Models\ " could not be resolved to a class" {"channel":"LSP-REF"} []
[2025-02-20 15:09:21] phpactor.INFO: Could not locate definition ""Could not locate any references to variable" {"channel":"LSP-REF"} []
[2025-02-20 15:09:26] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.env.example"},"text":" *omitting for security* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.env.example" {"channel":"LSP"} []
[2025-02-20 15:09:27] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.env.example"},"text":" *omitting for security* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.env.example" {"channel":"LSP"} []
[2025-02-20 15:09:27] phpactor.WARNING: The process was killed {"channel":"LSP"} []
[2025-02-20 15:09:27] phpactor.WARNING: Killed process "55199" ('/opt/homebrew/Cellar/php/8.4.3/bin/php' '/Users/ollie.beckwith/Library/Application Support/Zed/extensions/work/php/phpactor-2024.11.28.1/phpactor.phar' 'language-server:diagnostics' '--uri=file:///Users/ollie.beckwith/Documents/sites/project/app/Models/Order.php' '--config-extra={"worse_reflection.enable_context_location": false}') because it lived longer than 5s {"channel":"LSP"} []
[2025-02-20 15:09:29] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.env"},"text":" *omitting for security* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.env" {"channel":"LSP"} []
[2025-02-20 15:09:33] phpactor.WARNING: The process was killed {"channel":"LSP"} []
[2025-02-20 15:09:33] phpactor.WARNING: Killed process "55285" ('/opt/homebrew/Cellar/php/8.4.3/bin/php' '/Users/ollie.beckwith/Library/Application Support/Zed/extensions/work/php/phpactor-2024.11.28.1/phpactor.phar' 'language-server:diagnostics' '--uri=file:///Users/ollie.beckwith/Documents/sites/project/app/Models/Order.php' '--config-extra={"worse_reflection.enable_context_location": false}') because it lived longer than 5s {"channel":"LSP"} []

It never restarts itself after this happens and I have to manually restart phpactor.

OliverBeckwith avatar Feb 20 '25 15:02 OliverBeckwith

Yes I have also found out that logging kills the performance of phpactor. It would be interesting to see what code actions are slowing you down. You have to enable profiling for the language server seperately then you can see the performance of your code actions.

    "language_server.profile": true

mamazu avatar Feb 20 '25 15:02 mamazu

Here is a log of it happening again with that profiling flag enabled.

But just as a side note, I only enabled logging after this issue began occurring in order to see if I could see why, and I have allocated 3GB of memory under core.min_memory_limit in case it was simply running out of memory due to the codebase size.

Interestingly, this time there are no logs for the process being killed, but it was still stuck as resolving code actions.

Hope this means something to you:

[2025-02-20 15:38:25] phpactor.INFO: Listening on STDIO {"channel":"LSP"} []
[2025-02-20 15:38:25] phpactor.INFO: PROF        >> request #0 [initialize] {"channel":"LSP"} []
[2025-02-20 15:38:25] phpactor.INFO: PROF 0.0009 << request #0 [initialize] {"channel":"LSP"} []
[2025-02-20 15:38:25] phpactor.INFO: PROF        >> notification [initialized] {"channel":"LSP"} []
[2025-02-20 15:38:25] phpactor.INFO: Starting service: diagnostics (Phpactor\LanguageServer\Service\DiagnosticsService) {"channel":"LSP"} []
[2025-02-20 15:38:25] phpactor.INFO: Starting service: indexer (Phpactor\Extension\LanguageServerIndexer\Handler\IndexerHandler) {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 4.4607 << notification [initialized] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"workspace\/didChangeConfiguration","params":{"settings":[]}}): Exception [Phpactor\LanguageServer\Core\Handler\HandlerNotFound] Handler "workspace/didChangeConfiguration" not found, available handlers: "phpactor/debug/config", "phpactor/debug/workspace", "phpactor/status", "phpactor/service/start", "phpactor/service/stop", "phpactor/service/running", "workspace/executeCommand", "workspace/didChangeWatchedFiles", "textDocument/didOpen", "textDocument/didChange", "textDocument/didClose", "textDocument/didSave", "textDocument/willSave", "textDocument/willSaveWaitUntil", "phpactor/stats", "textDocument/codeAction", "textDocument/completion", "completionItem/resolve", "textDocument/signatureHelp", "textDocument/definition", "textDocument/typeDefinition", "textDocument/references", "textDocument/implementation", "textDocument/documentHighlight", "phpactor/indexer/reindex", "workspace/symbol", "textDocument/hover", "textDocument/documentSymbol", "textDocument/selectionRange", "textDocument/prepareRename", "textDocument/rename", "workspace/willRenameFiles" {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0002 << notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0139 << notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #2 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0076 << request #2 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0001 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #3 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0055 << request #3 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #4 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0003 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #5 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0080 << request #5 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #6 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0001 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.2395 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0003 << notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> request #7 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0056 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0055 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.0066 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.2863 << request #4 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF 0.2717 << request #6 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:29] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF        >> notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF 0.0277 << notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF        >> request #8 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF 0.0057 << request #8 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF        >> request #9 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF 0.0283 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:30] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0071 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> request #10 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0056 << request #10 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> request #11 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0001 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0062 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0001 << notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0199 << request #11 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.2259 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> request #12 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF 0.0055 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:31] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:34] phpactor.INFO: PROF        >> notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:34] phpactor.INFO: PROF 0.0054 << notification [textDocument/didOpen] {"channel":"LSP"} []
[2025-02-20 15:38:34] phpactor.INFO: PROF        >> request #13 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:34] phpactor.INFO: PROF 0.0741 << request #13 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> request #14 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF 0.0055 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> request #15 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF 0.0049 << request #15 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> request #16 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF 0.0042 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:35] phpactor.INFO: PROF 0.4119 << request #14 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.1660 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0001 << notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> request #17 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> request #18 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> request #19 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0253 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.8899 << request #16 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.1146 << notification [textDocument/didChange] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF        >> request #20 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:36] phpactor.INFO: PROF 0.0042 << request #20 [textDocument/documentHighlight] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.1343 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0001 << notification [workspace/didChangeWatchedFiles] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0054 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0054 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF 0.0845 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> request #21 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:37] phpactor.INFO: PROF        >> request #22 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> request #23 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 0.0056 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 0.0053 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 1.9118 << request #17 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 1.9115 << request #18 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 1.9113 << request #19 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 0.0039 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF        >> notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"workspace\/didChangeConfiguration","params":{"settings":[]}}): Exception [Phpactor\LanguageServer\Core\Handler\HandlerNotFound] Handler "workspace/didChangeConfiguration" not found, available handlers: "phpactor/debug/config", "phpactor/debug/workspace", "phpactor/status", "phpactor/service/start", "phpactor/service/stop", "phpactor/service/running", "workspace/executeCommand", "workspace/didChangeWatchedFiles", "textDocument/didOpen", "textDocument/didChange", "textDocument/didClose", "textDocument/didSave", "textDocument/willSave", "textDocument/willSaveWaitUntil", "phpactor/stats", "textDocument/codeAction", "textDocument/completion", "completionItem/resolve", "textDocument/signatureHelp", "textDocument/definition", "textDocument/typeDefinition", "textDocument/references", "textDocument/implementation", "textDocument/documentHighlight", "phpactor/indexer/reindex", "workspace/symbol", "textDocument/hover", "textDocument/documentSymbol", "textDocument/selectionRange", "textDocument/prepareRename", "textDocument/rename", "workspace/willRenameFiles" {"channel":"LSP"} []
[2025-02-20 15:38:38] phpactor.INFO: PROF 0.0000 << notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:39] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:39] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.env.example"},"text":" *omitted* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.env.example" {"channel":"LSP"} []
[2025-02-20 15:38:39] phpactor.INFO: PROF 0.0002 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF        >> notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"workspace\/didChangeConfiguration","params":{"settings":[]}}): Exception [Phpactor\LanguageServer\Core\Handler\HandlerNotFound] Handler "workspace/didChangeConfiguration" not found, available handlers: "phpactor/debug/config", "phpactor/debug/workspace", "phpactor/status", "phpactor/service/start", "phpactor/service/stop", "phpactor/service/running", "workspace/executeCommand", "workspace/didChangeWatchedFiles", "textDocument/didOpen", "textDocument/didChange", "textDocument/didClose", "textDocument/didSave", "textDocument/willSave", "textDocument/willSaveWaitUntil", "phpactor/stats", "textDocument/codeAction", "textDocument/completion", "completionItem/resolve", "textDocument/signatureHelp", "textDocument/definition", "textDocument/typeDefinition", "textDocument/references", "textDocument/implementation", "textDocument/documentHighlight", "phpactor/indexer/reindex", "workspace/symbol", "textDocument/hover", "textDocument/documentSymbol", "textDocument/selectionRange", "textDocument/prepareRename", "textDocument/rename", "workspace/willRenameFiles" {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF 0.0000 << notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.gitignore"},"text":" *omitted* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.gitignore" {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF 0.0001 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:43] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> request #24 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> request #25 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> request #26 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF 0.0040 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF 0.1721 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF 0.0054 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:44] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF        >> notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"textDocument\/didSave","params":{"textDocument":{"uri":"file:\/\/\/Users\/ollie.beckwith\/Documents\/sites\/project\/.gitignore"},"text":" *omitted* "}}): Exception [Phpactor\LanguageServer\Core\Workspace\Exception\UnknownDocument] Unknown text document "file:///Users/ollie.beckwith/Documents/sites/project/.gitignore" {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF 0.0001 << notification [textDocument/didSave] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:45] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> request #27 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> request #28 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> request #29 [textDocument/codeAction] {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF 0.1747 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF 0.0039 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF 0.0055 << code-action [TolerantCodeActionProvider] replace qualifier with importer {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:38:46] phpactor.INFO: PROF        >> code-action [TolerantCodeActionProvider] import unresolvable class names {"channel":"LSP"} []
[2025-02-20 15:39:06] phpactor.INFO: PROF        >> notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:39:06] phpactor.ERROR: Error when handling "Phpactor\LanguageServer\Core\Rpc\NotificationMessage" ({"jsonrpc":"2.0","method":"workspace\/didChangeConfiguration","params":{"settings":[]}}): Exception [Phpactor\LanguageServer\Core\Handler\HandlerNotFound] Handler "workspace/didChangeConfiguration" not found, available handlers: "phpactor/debug/config", "phpactor/debug/workspace", "phpactor/status", "phpactor/service/start", "phpactor/service/stop", "phpactor/service/running", "workspace/executeCommand", "workspace/didChangeWatchedFiles", "textDocument/didOpen", "textDocument/didChange", "textDocument/didClose", "textDocument/didSave", "textDocument/willSave", "textDocument/willSaveWaitUntil", "phpactor/stats", "textDocument/codeAction", "textDocument/completion", "completionItem/resolve", "textDocument/signatureHelp", "textDocument/definition", "textDocument/typeDefinition", "textDocument/references", "textDocument/implementation", "textDocument/documentHighlight", "phpactor/indexer/reindex", "workspace/symbol", "textDocument/hover", "textDocument/documentSymbol", "textDocument/selectionRange", "textDocument/prepareRename", "textDocument/rename", "workspace/willRenameFiles" {"channel":"LSP"} []
[2025-02-20 15:39:06] phpactor.INFO: PROF 0.0001 << notification [workspace/didChangeConfiguration] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF        >> notification [$/cancelRequest] {"channel":"LSP"} []
[2025-02-20 15:40:46] phpactor.INFO: PROF 0.0000 << notification [$/cancelRequest] {"channel":"LSP"} []

OliverBeckwith avatar Feb 20 '25 15:02 OliverBeckwith

Nothing immediately problematic, I mean some of the requests are taking a second but there's no explanation why. (Might have to look at the logs with log level debug but that produces A LOT of output. Generally Zed also is triggering an event that phpactor doesn't know workspace/didConfigurationChange. But that shouldn't be a problem.

As a recommendation if you want to play around with the settings, you can also try those options: This one will try to load classes by the composer path and not try to find the classes manually (probably a good idea with a big code base)

    "class_to_file.brute_force_conversion": false,

Don't index cache files and other things

        "indexer.exclude_patterns": [
        "/vendor/**/Tests/**/*",
        "/vendor/**/tests/**/*",
        "/vendor/composer/**/*",
        "/var/cache/**/*",
        "/**/Workspace/**/*"
    ],

mamazu avatar Feb 20 '25 16:02 mamazu

I have given that a try with "class_to_file.brute_force_conversion": false and with a number of exclude_patterns values, even going as far as excluding all of the vendor folder, and it still occurs when I save a few big files one after the other.

I am replicating this by just opening, putting a space at the end of a random line and quickly saving a few 1000+ line files one after the other, while mixing in a few non-php files like .gitignore and .env files. Seems to cause it to get stuck really consistently for me. I know it also happens for my colleagues as well that use Zed so it's at least not just my machine that's the issue. It is either our repo, or zed/phpactor. I will see if I can make it happen on a different repo.

OliverBeckwith avatar Feb 20 '25 16:02 OliverBeckwith

Basically Phpactor does not play well with large multi-thousand line files (if that's what you have), and it doesn't really play well with Laravel either (although that's a different topic). The good news is that I'm not working on a large legacy project so maybe I can find ways to improve it...

dantleech avatar Feb 20 '25 17:02 dantleech

Well for projects with big files the bottle neck will probably be the parser. Especially with bigger files an incremental parser would be nice so that only the parts that have change would need to be updated. But that's a very big undertaking.

mamazu avatar Feb 20 '25 18:02 mamazu

Thanks for the attention on this. I was just thinking of having a play around with phpactor locally (was planning to throw a bunch of dumps around just to get an idea of how it works and if I would be able to contribute at all), and the included bin/phpactor works fine in terminal, but if I give it to Zed (via the lsp.phpactor.binary.path setting) I am getting some errors starting it. I know this isn't Zed support, but just wondering if anyone knows anything about this?

Error Zed throws:

2025-02-26T13:22:05.31653Z [INFO] attempting to start language server "phpactor", path: "/Users/ollie.beckwith/Documents/personal/phpactor", id: 17
2025-02-26T13:22:05.318358Z [INFO] starting language server process. binary path: "/Users/ollie.beckwith/Documents/personal/phpactor/bin/phpactor", working directory: "/Users/ollie.beckwith/Documents/personal/phpactor", args: []
2025-02-26T13:22:05.603792Z [ERROR] cannot read LSP message headers
2025-02-26T13:22:05.604131Z [ERROR] Broken pipe (os error 32)
2025-02-26T13:22:05.604417Z [ERROR] server shut down
2025-02-26T13:22:05.60451Z [ERROR] Failed to start language server "phpactor": oneshot canceled
2025-02-26T13:22:05.604619Z [ERROR] server stderr: ""

OliverBeckwith avatar Feb 26 '25 13:02 OliverBeckwith

If you want to use phpactor as a language server you need to run it like this: bin/phpactor language-server

mamazu avatar Feb 26 '25 15:02 mamazu

Unfortunately Zed doesn't like that either (Since the setting is for the path of the binary, I presume Zed will be starting it with language-server internally). With the vscode extension though I could replace the binary with the local repo bin/phpactor and it seems to work fine, so I will just use vscode to fiddle. Thanks

OliverBeckwith avatar Feb 26 '25 15:02 OliverBeckwith

2025-02-26T13:22:05.318358Z [INFO] starting language server process. binary path: "/Users/ollie.beckwith/Documents/personal/phpactor/bin/phpactor", working directory: "/Users/ollie.beckwith/Documents/personal/phpactor", args: []

In the second line of your debug output there is an "args" parameter, that's probably where this goes.

mamazu avatar Feb 26 '25 15:02 mamazu

That has made it work thank you. I had assumed the other values I wasn't setting would carry over from the default configuration 🤦

OliverBeckwith avatar Feb 26 '25 15:02 OliverBeckwith