Fork me on GitHub
Slack Archive

This page is not created by, affiliated with, or supported by Slack Technologies, Inc.

2023-05-29

Channels

#lsp
<
2023-05-29
>
simonkatz09:05:19

I’m using clojure-lsp with Emacs (pretty recent versions of everything), and I think clojure-lsp is doing unnecessary work when :paths-ignore-regex is used. I’ve used {:paths-ignore-regex [".*edn"]} in my .lsp/config.edn and run M-x lsp-workspace-restart. Now when I visit an edn file, as expected that stops showing lsp linting messages in Emacs (both in the echo area and lsp-ui), but I see activity in my clojure-lsp log file and I see that clojure-lsp is using the CPU. Am I right in thinking that this is unexpected behaviour? (I was expecting clojure-lsp to be doing no significant work.) For large edn files, this is enough to make Emacs sluggish. For very large edn files, I think there may be a separate problem — I see stackoverflow errors in the logs. I can create tickets for these if it would help.

simonkatz09:05:41

I’ve added an Emacs hack to avoid using lsp for large files, so this is not at all urgent.

ericdallo12:05:01

would be nice to understand what extra work is that even with the ignore regex

simonkatz13:05:53

Here’s some of the log file output: 

2023-05-29T13:39:04.938Z  INFO [clojure-lsp.handlers:281] - :document-highlight 0ms
2023-05-29T13:39:04.939Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:07.082Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:12.359Z  INFO [clojure-lsp.handlers:281] - :document-highlight 0ms
2023-05-29T13:39:12.360Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:15.312Z  INFO [clojure-lsp.handlers:281] - :document-highlight 0ms
2023-05-29T13:39:15.313Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:17.632Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:18.473Z  INFO [clojure-lsp.handlers:281] - :document-highlight 0ms
2023-05-29T13:39:18.473Z  INFO [clojure-lsp.handlers:274] - :document-symbol 1ms
2023-05-29T13:39:18.474Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:39:18.475Z  INFO [clojure-lsp.handlers:453] - :code-lens 0ms
2023-05-29T13:39:18.527Z  INFO [clojure-lsp.feature.file-management:250] - changes analyzed by clj-depend took 0ms
2023-05-29T13:39:18.527Z  INFO [clojure-lsp.feature.file-management:246] - changes analyzed by clj-kondo took 0ms
2023-05-29T13:39:18.528Z  INFO [clojure-lsp.dep-graph:269] - :maintain-dep-graph 0ms
2023-05-29T13:39:18.528Z  INFO [clojure-lsp.server:550] - :analyze-file 1ms
2023-05-29T13:39:18.530Z  INFO [clojure-lsp.feature.file-management:139] - :reference-files/find 2ms
2023-05-29T13:39:18.530Z  INFO [clojure-lsp.feature.file-management:137] - :notify-references 2ms
2023-05-29T13:39:18.558Z  INFO [clojure-lsp.server:102] - :publish-diagnostics 0ms
2023-05-29T13:39:18.569Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
2023-05-29T13:40:06.097Z  INFO [clojure-lsp.handlers:281] - :document-highlight 0ms
2023-05-29T13:40:06.099Z  INFO [clojure-lsp.handlers:441] - :code-actions 1ms
Is that helpful?

ericdallo13:05:26

All of that is expected, since there lots of lap features and those can't be disable via server, but that's not what affects performance, you can see how they take 1ms or 0ms since probably there are no analysis for that file

simonkatz13:05:15

Oh, those messages above were for a small file. Here’s some output for a large file. ^^

ericdallo13:05:08

That exception is definitely not good, even so, not sure how other features are taking time if they have no analysis. Is it possible to create a repo showing those issues?

simonkatz13:05:04

Sure. I have one already. Give me a minute to add the config and the big file.

simonkatz14:05:30

See the repo https://github.com/simon-katz/bug-report-clojure-lsp-ignored-edn-high-cpu The above log messages came when playing with the file edn-files/big-2000-4.edn.

ericdallo14:05:59

Thanks, will take a look soon today

simonkatz14:05:12

Cool; thank you

simonkatz14:05:42

As I said, I’ve added an Emacs hack to avoid using lsp for large files, so this is not at all urgent.

ericdallo15:05:43

I think I know what it's happening, the :paths-ignore-regex is used only for analysis of paths which happens for classpath analysis and project analysis during startup, but when you open a file manually we always analyze that file https://github.com/clojure-lsp/clojure-lsp/blob/8a0c2e71681a0b9890b603dcea1ee29e918d58e3/lib/src/clojure_lsp/kondo.clj#L270

ericdallo15:05:03

I'm wondering if we should check if for files opened as well, I guess so

ericdallo15:05:22

I can repro the issue in the very-big edn filei, t's probably something to be fixed indeed

ericdallo15:05:52

so, I found the root cause, it's caused by performance of rewrite-clj when parsing a huge node, like a map of 100k lines takes ~1s. I think that's is kinda of expected for a node of that size, what we can do is try to check :paths-ignore-regex for that as well, but it's not a analysis issue in the end

ericdallo16:05:15

@U06A9U5RP I just made a commit to clojure-lsp's master improving paths-ignore-regex to really ignore those features for LSP, that fixed the high cpu on that huge edn file, hope it works for you, you can test it with a nightly build #C032YH7P0R2

simonkatz16:05:36

Great, and thanks. I'll try it out tomorrow.

simonkatz21:05:45

@UKFSJSM38 Ah, the nightly was built soon after your commit. I’ve tried it out and, yes, it’s a lot better. I still see the stack overflow errors in the logs, but I think clojure-lsp is using less CPU than before and Emacs is remaining pretty responsive. Example log output for edn-files/very-big-10000-26.edn: 

2023-05-29T21:40:54.002Z  INFO [clojure-lsp.handlers:143] - :hover - skipped
2023-05-29T21:40:54.013Z  INFO [clojure-lsp.handlers:143] - :code-actions - skipped
2023-05-29T21:40:54.016Z  INFO [clojure-lsp.handlers:143] - :document-highlight - skipped
2023-05-29T21:40:55.580Z  INFO [clojure-lsp.handlers:143] - :code-actions - skipped
2023-05-29T21:40:55.583Z  INFO [clojure-lsp.handlers:143] - :document-highlight - skipped
2023-05-29T21:40:55.585Z  INFO [clojure-lsp.handlers:143] - :hover - skipped
2023-05-29T21:40:57.645Z  ERROR [clojure-lsp.server:55] - Error receiving message: Internal error (-32603)
{:id 1663, :method "textDocument/documentSymbol"}
                                         ...                                  
                      clojure.core/concat/fn                     core.clj: 727
                            clojure.core/seq                     core.clj: 139
                                         ...                                  
                      clojure.core/concat/fn                     core.clj: 727
                            clojure.core/seq                     core.clj: 139
                                         ...                                  
                      clojure.core/concat/fn                     core.clj: 727
                            clojure.core/seq                     core.clj: 139
                                         ...                                  
                      clojure.core/concat/fn                     core.clj: 727
                            clojure.core/seq                     core.clj: 139
...

[...many more like the above lines, then...]

com.oracle.svm.core.graal.snippets.StackOverflowCheckImpl.throwNewStackOverflowError  StackOverflowCheckImpl.java: 309
     com.oracle.svm.core.graal.snippets.StackOverflowCheckImpl.newStackOverflowError  StackOverflowCheckImpl.java: 329
    com.oracle.svm.core.graal.snippets.StackOverflowCheckImpl.newStackOverflowError0  StackOverflowCheckImpl.java: 333
java.lang.StackOverflowError:

ericdallo23:05:33

ah my bad, forgot to add that feature to the skipped features, did one more commit

simonkatz11:05:35

@UKFSJSM38 Thanks — that’s all looking good now.

👍 2