Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
OliverBeckwith opened this issue Feb 20, 2025 · 11 comments
Open

Comments

@OliverBeckwith
Copy link

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.

@mamazu
Copy link
Contributor

mamazu commented Feb 20, 2025

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

@OliverBeckwith
Copy link
Author

OliverBeckwith commented Feb 20, 2025

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"} []

@mamazu
Copy link
Contributor

mamazu commented Feb 20, 2025

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/**/*"
    ],

@OliverBeckwith
Copy link
Author

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.

@dantleech
Copy link
Collaborator

dantleech commented Feb 20, 2025

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...

@mamazu
Copy link
Contributor

mamazu commented Feb 20, 2025

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.

@OliverBeckwith
Copy link
Author

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: ""

@mamazu
Copy link
Contributor

mamazu commented Feb 26, 2025

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

@OliverBeckwith
Copy link
Author

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

@mamazu
Copy link
Contributor

mamazu commented Feb 26, 2025

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.

@OliverBeckwith
Copy link
Author

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants