Fork me on GitHub
#lsp
<
2021-09-30
>
Jakub Holý (HolyJak)10:09:17

Hi! I have tried again clojure-lsp (from IntelliJ) and it is again consuming 350% of my CPU. It is now 10:51 but the log does not tell me much:

10:49:42.427Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:43.231Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.008Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.104Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.134Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.389Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.557Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.591Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.699Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:44.740Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:45.815Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:57.554Z DEBUG [clojure-lsp.server:?] - :didChange 1ms
10:49:57.648Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.123Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.262Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.408Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.444Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.516Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:58.642Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:49:59.363Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:00.515Z DEBUG [clojure-lsp.server:?] - :didChange 1027ms
10:50:01.369Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:01.486Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:01.501Z DEBUG [clojure-lsp.server:?] - :didSave 0ms
10:50:01.501Z DEBUG [clojure-lsp.server:?] - :didSave 0ms
10:50:22.613Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:22.817Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:25.195Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:25.322Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:25.489Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:32.575Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:34.988Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:35.779Z DEBUG [clojure-lsp.server:?] - :didChange 1ms
10:50:35.938Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.076Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.093Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.110Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.208Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.363Z DEBUG [clojure-lsp.server:?] - :didChange 1ms
10:50:36.391Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:36.407Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:38.700Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:41.500Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:42.941Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:43.061Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:43.090Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:52.149Z DEBUG [clojure-lsp.server:?] - :didChange 0ms
10:50:55.584Z DEBUG [clojure-lsp.server:?] - :didSave 0ms
Any tips how to troubleshoot why is it so busy?

Akiz11:09:48

I had got big cpu hit when lsp-log-io has been enabled - this helped me (in emacs) (setq lsp-log-io nil)

Akiz11:09:12

But that should be disabled by default..

ericdallo12:09:38

@U0522TWDA are you using latest clojure-lsp? Could you create a sample project where I could test it as well?

Jakub Holý (HolyJak)12:09:06

clojure-lsp 2021.09.13-22.25.35 I have not seen issues with it on other projects (via Calva) so I suppose it is specific to this, rather large, project that I cannot share 😞 I will try to open it in Calva to make sure it is not just the IntelliJ <> clojure-lsp integration.

ericdallo12:09:27

Yeah, I can tell from this log, that client is sending a log of didChange requests, that are requests sent when a file is changed, but there are too many in a small time range, which looks odd

👍 1
ericdallo12:09:45

each one of these didChange requests, clojure-lsp analyze the file with kondo, it has a smart debounce to not kondo all the time though of 100ms though

Jakub Holý (HolyJak)12:09:06

It could be IntelliJ or the lsp plugin doing something weird to those files. I certainly changed max 1-2.

Jakub Holý (HolyJak)12:09:17

I will see how the project works with Calva.

👍 1
Jakub Holý (HolyJak)12:09:06

(I just opened the project in Calva, clojure-lsp is close to 100% CPU, which is I guess expected for a newly opened stuff, and far less than under intellij)

ericdallo12:09:44

yes, for the first startup it should take some time

Jakub Holý (HolyJak)10:10:23

@ericdallo I have confirmed that the same project behaves OK in Calva so it seems the excessive CPU use is indeed caused by the IntelliJ LSP plugin sending too many didChange events. I have opened https://github.com/gtache/intellij-lsp/issues/166 but I do not expect it to get fixed, the project has many issues and seems not very active. Could clojure-lsp be smarter and check itself for whether a file has actually been changed or not since the last time?

ericdallo12:10:50

That's sad 😢 clojure-lsp ready does a debounce of 300ms, even so it would be a bad performance compare the whole string of the buffer to check if it is equal maybe do a checksum? Not sure if it would help

ericdallo12:10:15

It'd be really good if we could hack the LSP plugin to fix that

Jakub Holý (HolyJak)16:10:04

the question is whether the LSP plugin is not lying. Perhaps checking the timestamp of the file would be enough.

Jakub Holý (HolyJak)16:10:14

Checksum would also be an (more reliable?) option, especially if there is one that is really fast. I imagine it would still be faster than a kondo run. Though it would impact also processing time of fiiles that did change. Perhaps it could be behind a flag?

Jakub Holý (HolyJak)16:10:52

I would start by checking the last modif. time of the file in question. But I guess I as a user of clojure-lsp have no easy way to do so?

ericdallo16:10:56

Yes, we can try that

ericdallo16:10:29

Yeah, I don't know if checking the file timestamp is fastest than checking checksum

ericdallo16:10:39

Also, we don't save the timestamp to compare

ericdallo16:10:51

But we do sabe the file content

Jakub Holý (HolyJak)16:10:09

I imagine that getting the time stamp from the FS is much faster than actually computing any hash but I might be wrong 🙂

ericdallo16:10:44

the issue is that clojure-lsp at the moment only has the file content at the time

ericdallo16:10:53

but we can improve to get the filename and check the timestamp

ericdallo16:10:19

feel free to open an issue on clojure-lsp describing this disucussion

ericdallo13:09:53

clojure-lsp Released clojure-lsp https://github.com/clojure-lsp/clojure-lsp/releases/tag/2021.09.30-12.28.16 and 2021.09.30-15.28.01, one of the biggest releases of the project! • General ◦ Use lower-case for refer/import/require sorting. https://github.com/clojure-lsp/clojure-lsp/issues/560 https://github.com/clojure-lsp/clojure-lsp/issues/561 c/c @dpsutton ◦ Avoid removing comments when sorting/cleaning namespace. https://github.com/clojure-lsp/clojure-lsp/issues/559 ◦ Break lines when sorting refers along with then new `:clean :sort :refer :max-line-length` setting with a default of `80`. https://github.com/clojure-lsp/clojure-lsp/issues/562 ◦ Deprecate `lens-segregate-test-references` in favor to `:code-lens :segregate-test-references` ◦ Check for a default `.cljfmt.edn` config file for cljfmt config settings if no `:cljfmt-config-path` was provided. https://github.com/clojure-lsp/clojure-lsp/issues/563 c/c @pez @brandon.ringe @amithgeorge ◦ Bump clj-kondo to `2021.09.25` fixing false-positives with potemkin import-var analysis. ◦ Re-scan whole project if any clj-kondo config changed for better consistence. https://github.com/clojure-lsp/clojure-lsp/issues/331 c/c @borkdude ◦ Fix clojure-lsp not initializing when empty `project.clj`. https://github.com/clojure-lsp/clojure-lsp/issues/579 c/c @paulbutcher ◦ Support finding config in classpath via new setting`:classpath-config-paths ["my-org/my-lib"]`. https://github.com/clojure-lsp/clojure-lsp/issues/580 • Editor ◦ Fix `resolve macro as` code action after regression introduced recently. ◦ Fix `unused-public-var` not being suppressed during project startup. https://github.com/clojure-lsp/clojure-lsp/issues/554 ◦ Improve `hover` feature to return elements when inside a function call. https://github.com/clojure-lsp/clojure-lsp/issues/569 c/c @ccann ◦ Fix `create-private-function` command and code action to consider when new function is inside thread macros. ◦ Support `$/progress` LSP feature, sending notifications for client when server is starting, improving the feedback for the user. ◦ Improve semantic tokens support for java classes and methods. • API/CLI ◦ Support renaming namespaces as well with `rename` feature. ◦ Use relative paths instead of absolute paths on diff messages. ◦ Add `analyze-project!` to analyze whole project only and cache analysis, useful for REPL usage for example. ◦ Follow same exit status from clj-kondo for `diagnostics` feature. https://github.com/clojure-lsp/clojure-lsp/issues/572 c/c @thiagokokada ◦ Improve API start project feedback reporting the percentage and specific message. This release focused on fixing a lot of issues to make clojure-lsp a more stable and reliable tool along with improved user feedback, as example check the gif, now clojure-lsp reports the progress during initialization loading 🚀 This release was supported by https://www.clojuriststogether.org/ clojurists-together gratitude

🎉 15
gratitude 5
🙏 3
💜 4
clojure-lsp 4
aw_yeah 2
catjam 4
awesome 1
anonimitoraf13:09:55

Thanks for these changes! I just noticed, lsp-ui-doc doesn't seem to show up for me anymore. In my webm, I can invoke lsp-ui-doc-glance for Typescript LSP but not for Clojure LSP

ericdallo14:09:34

Hum, not sure what lsp-ui-doc-glance call, but probably it's related with the issue #569

anonimitoraf14:09:05

Oh, it's essentially just like lsp-ui-doc-show

anonimitoraf14:09:22

Does that still work for you? (It seems to not work for me as well)

ericdallo14:09:47

I'll give a try

ericdallo15:09:16

I found the issue

ericdallo15:09:23

I'll try to do a quick fix

ericdallo15:09:46

TIL: glance is a cool feature :)

catjam 4
ericdallo16:09:03

Released new version fixing this, thanks for the quick report!

anonimitoraf21:09:11

Thanks for the quick fix!

👍 1
Jakub Holý (HolyJak)10:10:23
replied to a thread:Hi! I have tried again clojure-lsp (from IntelliJ) and it is again consuming 350% of my CPU. It is now 10:51 but the log does not tell me much: 10:49:42.427Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:43.231Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.008Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.104Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.134Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.389Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.557Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.591Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.699Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:44.740Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:45.815Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:57.554Z DEBUG [clojure-lsp.server:?] - :didChange 1ms 10:49:57.648Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.123Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.262Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.408Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.444Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.516Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:58.642Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:49:59.363Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:00.515Z DEBUG [clojure-lsp.server:?] - :didChange 1027ms 10:50:01.369Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:01.486Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:01.501Z DEBUG [clojure-lsp.server:?] - :didSave 0ms 10:50:01.501Z DEBUG [clojure-lsp.server:?] - :didSave 0ms 10:50:22.613Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:22.817Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:25.195Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:25.322Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:25.489Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:32.575Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:34.988Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:35.779Z DEBUG [clojure-lsp.server:?] - :didChange 1ms 10:50:35.938Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.076Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.093Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.110Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.208Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.363Z DEBUG [clojure-lsp.server:?] - :didChange 1ms 10:50:36.391Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:36.407Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:38.700Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:41.500Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:42.941Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:43.061Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:43.090Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:52.149Z DEBUG [clojure-lsp.server:?] - :didChange 0ms 10:50:55.584Z DEBUG [clojure-lsp.server:?] - :didSave 0ms Any tips how to troubleshoot why is it so busy?

@ericdallo I have confirmed that the same project behaves OK in Calva so it seems the excessive CPU use is indeed caused by the IntelliJ LSP plugin sending too many didChange events. I have opened https://github.com/gtache/intellij-lsp/issues/166 but I do not expect it to get fixed, the project has many issues and seems not very active. Could clojure-lsp be smarter and check itself for whether a file has actually been changed or not since the last time?