Fork me on GitHub
#lsp
<
2022-03-25
>
sakalli11:03:32

Hey, I realize this could be a local issue, and I apologize for not being able to provide much context right now, but fwiw I'm seeing this kind of memory use with clojure-lsp right now. Imagining that this isn't normal nor expected behavior:

clojure-lsp 2022.02.23-12.12.12
clj-kondo 2022.03.10-SNAPSHOT
lsp-mode 8.0.0
GNU Emacs 28.0.91 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.31, cairo version 1.17.4) of 2022-02-18

ericdallo11:03:46

Oh, sounds odd, how many clojure-lsp process are running?

ericdallo11:03:07

We fixed some possible infinite loops corner cases, could you test a nightly release from #clojure-lsp-builds?

sakalli11:03:32

sure, cheers

borkdude11:03:47

@UKFSJSM38 Maybe it's time for a new release for this infinite loop fix?

ericdallo11:03:50

Yes, I was planning to do a release tomorrow, but there is no reason why wait, are you planning to release kondo so I can bump before release it?

borkdude11:03:46

@UKFSJSM38 I was going to work on the java analysis a bit more, maybe it would be nice to get that in, but I guess you would also need time to process things on the clojure-lsp side right?

ericdallo11:03:10

Yes, no problem we leave that for a next one IMO

borkdude11:03:55

then I think clojure-lsp could use the snapshot version, I don't have a reason to release clj-kondo now

ericdallo11:03:30

Will release it today so

🙏 1
sakalli14:03:16

It appears to operate better with the most recent nightly, which swings from 1-2 gigabytes, which is not insignificant but possibly to be expected. I also placed an order for extra ram.😂

ericdallo14:03:17

1-2 is expected indeed

👍 1
ericdallo16:03:38

Found a regression in diagnostics, will hold release until fix

genmeblog22:03:14

just hit that...

ericdallo22:03:00

I fixed the issue and I'm releasing a new version, it will be available as soon CI helps 😂

🙏 1
borkdude22:03:32

was the regression causing the high cpu usage or was @U1EP3BZ3Q hitting the old bug?

ericdallo22:03:44

the regression was not related with this issue

🎉 1
genmeblog22:03:43

@U04V15CAJ it was the latest stable version

clojure-lsp 2022.02.23-12.12.12
clj-kondo 2022.02.09

sakalli13:03:34

can also confirm that I just hit this behaviour (and emacs hanging) on:

clojure-lsp 2022.02.23-12.12.12
clj-kondo 2022.03.10-SNAPSHOT
clojure-lsp is using 5.4GB currently.

borkdude13:03:58

@U0FMV3MDK have you used the newest version?

borkdude13:03:02

doesn't look like it?

borkdude13:03:17

I see the same version as in your original message

sakalli13:03:15

hmm. ah ok, sorry about that. thought i had, but alas not. will update now.

sakalli13:03:38

so nevermind

genmeblog11:03:36

@UKFSJSM38 still the same 😕 lsp eats tones of memory and cpu and freeze emacs quite often (for more than minute or so).

genmeblog11:03:06

$ /usr/local/bin/clojure-lsp --version
clojure-lsp 2022.03.26-18.47.08
clj-kondo 2022.03.10-SNAPSHOT

genmeblog11:03:07

The top was 12gb ram (15gb) on 16gb wsl2 machine

genmeblog11:03:29

The experience looks like that: typing few lines of code, everything freezes, cpu and ram consumption is maximum (by clojure-lsp), emacs freezes for 60-120 seconds, then things unfreeze, ram goes down to 6g, and over again

genmeblog11:03:23

The namespace I work on is quite big and rich in functions (4200 loc).

borkdude12:03:12

is it possible to export that code so we can reproduce?

genmeblog12:03:36

I'm trying to add new function. Let me share my emacs config.

genmeblog12:03:40

Restarted emacs recently, opened color.clj , cider-jack-in-clj , evaluated everything via cider-load-buffer C-c C-k and started typing.

genmeblog12:03:10

5 minutes lated (now):

genmeblog12:03:22

unfrozen eventually (now)

borkdude13:03:15

ok, yes, it's quite a big file and linting it costs on my machine .5s which is quite long but still doable. but I can imagine clojure-lsp is doing a ton more

borkdude13:03:27

$ clj-kondo --lint src/clojure2d/color.clj
...
linting took 549ms, errors: 2, warnings: 7

ericdallo13:03:12

That's quite odd, there are some of things to check: • Check lsp-doctor is ok (you don't need the optional ones, although is a nice to have) • Check server logs when it freezes, it may help find where it's freezing • Maybe test without cider to avoid more noise

borkdude13:03:59

but on my machine it's acting quite normal in that file

borkdude13:03:04

no huge CPU or memory usage

👍 2
ericdallo13:03:13

@U07M2C8TT FYI, maybe we still have issues with that infinite loop for huge buffers, we need to repro to make sure

borkdude13:03:00

I might have disabled some stuff like watchers that have caused problems in the past

genmeblog13:03:56

lsp-doctor says:

Checking for Native JSON support: OK
Check emacs supports `read-process-output-max': OK
Check `read-process-output-max' default has been changed from 4k: ERROR
Byte compiled against Native JSON (recompile lsp-mode if failing when Native JSON available): OK
`gc-cons-threshold' increased?: OK
Using `plist' for deserialized objects? (refer to ): OPTIONAL
Using emacs 28+ with native compilation?: OPTIONAL

ericdallo13:03:53

You should fix that read-proccess-output-max on your config

borkdude13:03:52

This is my output:

Checking for Native JSON support: OK
Check emacs supports `read-process-output-max': OK
Check `read-process-output-max' default has been changed from 4k: OK
Byte compiled against Native JSON (recompile lsp-mode if failing when Native JSON available): OK
`gc-cons-threshold' increased?: OK
Using gccemacs with emacs lisp native compilation (): NOT AVAILABLE (OPTIONAL)

ericdallo13:03:36

This should help with performance, even so, it should not freeze

genmeblog13:03:05

ok, fixinп it and proceeding further, when to find server logs, in *lsp-log*?

genmeblog13:03:26

got it! (rtfm 🙂 - note to myself)

borkdude13:03:56

completely unrelated but I've been wondering why there is the word "blog" in your handles :)

genmeblog13:03:46

tbh I don't remember 😄

😆 1
genmeblog13:03:16

Possibly gmail forced me to use some lastname

genmeblog13:03:22

originally I used this mainly for presenting generative art stuff but things I make grew in so many directions... it's hard to change this now 🙂

👍 1
genmeblog13:03:30

Ok, going back to got it hanged again...

genmeblog13:03:34

2022-03-29T13:54:48.348Z  DEBUG [clojure-lsp.server:71] - :hover 24ms

2022-03-29T13:55:39.409Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:39.409Z  WARN [clojure-lsp.server:64] - Timeout in :code-lens waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:39.409Z  DEBUG [clojure-lsp.server:71] - :codeAction 60037ms
2022-03-29T13:55:39.409Z  DEBUG [clojure-lsp.server:71] - :codeLens 60059ms
2022-03-29T13:55:39.809Z  WARN [clojure-lsp.server:64] - Timeout in :code-lens waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:39.809Z  DEBUG [clojure-lsp.server:71] - :codeLens 60190ms
2022-03-29T13:55:40.209Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:40.210Z  DEBUG [clojure-lsp.server:71] - :codeAction 60077ms
2022-03-29T13:55:43.835Z  WARN [clojure-lsp.server:64] - Timeout in :code-lens waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:43.835Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:43.835Z  DEBUG [clojure-lsp.server:71] - :codeLens 60178ms
2022-03-29T13:55:43.835Z  DEBUG [clojure-lsp.server:71] - :codeAction 60156ms
2022-03-29T13:55:47.068Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:47.068Z  DEBUG [clojure-lsp.server:71] - :codeAction 60030ms
2022-03-29T13:55:48.869Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:48.869Z  DEBUG [clojure-lsp.server:71] - :codeAction 60095ms
2022-03-29T13:55:49.870Z  WARN [clojure-lsp.server:64] - Timeout in :code-actions waiting for changes to file:///home/tsl/clojure/clojure2d/src/clojure2d/color.clj
2022-03-29T13:55:49.870Z  DEBUG [clojure-lsp.server:71] - :codeAction 60191ms
2022-03-29T13:56:30.835Z  INFO [clojure-lsp.server:61] - Refreshing testTree took 0.04 secs
2022-03-29T13:56:30.838Z  DEBUG [clojure-lsp.server:71] - :didChange 88252ms
2022-03-29T13:56:30.851Z  DEBUG [clojure-lsp.server:71] - :documentSymbol 12ms

genmeblog13:03:15

Here is the exact part of logs. It hanged after first line.

borkdude13:03:38

code action of 1 minute that seems quite strange

ericdallo14:03:56

Yeah, that's a not really the code action , but it's waiting for didChange to then process the action, we fixed that log yesterday 😅

ericdallo14:03:57

@U1EP3BZ3Q could you try the latest build at #clojure-lsp-builds, this specific debug will benefit of that fix

genmeblog14:03:13

Ok, 30 minutes (time for lunch 🙂 )

genmeblog14:03:19

why do zip file is in zip file?

$ unzip -l clojure-lsp-native-static-linux-amd64.zip
Archive:  clojure-lsp-native-static-linux-amd64.zip
  Length      Date    Time    Name
---------  ---------- -----   ----
 28083945  2022-03-29 02:08   clojure-lsp-native-static-linux-amd64.zip
---------                     -------
 28083945                     1 file
t

borkdude14:03:10

@U1EP3BZ3Q I wrote a script here to download the latest nightly: https://clojurians.slack.com/archives/CPABC1H61/p1648492930937569

🙏 1
borkdude14:03:23

It does extract the zip twice exactly because of that weird problem

genmeblog14:03:02

ah, ok, will use it next time. Another (minor) issue: version of nigthly build is the same as last released

genmeblog14:03:19

Here it is, latest snapshot, hangs as usual, logs are different:

genmeblog14:03:23

2022-03-29T14:34:45.075Z  INFO [clojure-lsp.handlers:234] - :document-highlight 19ms
2022-03-29T14:34:45.078Z  INFO [clojure-lsp.handlers:347] - :hover 21ms
2022-03-29T14:34:45.275Z  INFO [clojure-lsp.handlers:382] - :code-actions 218ms
2022-03-29T14:34:48.244Z  INFO [clojure-lsp.handlers:208] - :document-symbol 16ms
2022-03-29T14:34:53.179Z  INFO [clojure-lsp.handlers:140] - :completion 893ms - total items: 33
2022-03-29T14:35:45.071Z  INFO [clojure-lsp.server:105] - :refreshing-test-tree 132ms
2022-03-29T14:35:45.125Z  INFO [clojure-lsp.handlers:208] - :document-symbol 17ms
2022-03-29T14:35:45.125Z  INFO [clojure-lsp.handlers:208] - :document-symbol 17ms
2022-03-29T14:35:45.224Z  INFO [clojure-lsp.handlers:347] - :hover 116ms
2022-03-29T14:35:46.012Z  INFO [clojure-lsp.handlers:140] - :completion 758ms - total items: 14
2022-03-29T14:35:46.717Z  INFO [clojure-lsp.handlers:140] - :completion 1643ms - total items: 378
2022-03-29T14:35:46.977Z  INFO [clojure-lsp.feature.file-management:148] - changes analyzed by clj-kondo took 1569ms
2022-03-29T14:35:46.978Z  INFO [clojure-lsp.feature.file-management:144] - :analyze-file 1570ms
2022-03-29T14:35:47.034Z  INFO [clojure-lsp.handlers:234] - :document-highlight 42ms - waited 1271ms
2022-03-29T14:35:47.118Z  INFO [clojure-lsp.handlers:234] - :document-highlight 17ms - waited 58883ms
2022-03-29T14:35:47.130Z  INFO [clojure-lsp.handlers:234] - :document-highlight 30ms - waited 1876ms
2022-03-29T14:35:47.130Z  INFO [clojure-lsp.handlers:234] - :document-highlight 29ms - waited 2018ms
2022-03-29T14:35:47.143Z  INFO [clojure-lsp.handlers:395] - :code-lens 42ms - waited 2034ms
2022-03-29T14:35:47.157Z  INFO [clojure-lsp.handlers:395] - :code-lens 45ms - waited 58947ms
2022-03-29T14:35:47.299Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 41ms
2022-03-29T14:35:47.311Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 54ms
2022-03-29T14:35:47.312Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 54ms
2022-03-29T14:35:47.319Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 62ms
2022-03-29T14:35:47.322Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 64ms
2022-03-29T14:35:47.322Z  INFO [clojure-lsp.handlers:401] - :resolve-code-lens 64ms
2022-03-29T14:35:47.520Z  INFO [clojure-lsp.handlers:382] - :code-actions 527ms - waited 1757ms
2022-03-29T14:35:47.713Z  INFO [clojure-lsp.handlers:382] - :code-actions 613ms - waited 2602ms
2022-03-29T14:35:47.722Z  INFO [clojure-lsp.handlers:382] - :code-actions 622ms - waited 59488ms
2022-03-29T14:35:47.738Z  INFO [clojure-lsp.handlers:382] - :code-actions 637ms - waited 2483ms
2022-03-29T14:35:54.188Z  INFO [clojure-lsp.handlers:382] - :code-actions 459ms

genmeblog14:03:12

CPU around 800% constantly (8 cores asigned to a wsl)

ericdallo14:03:34

It's odd, something is taking 1minute

ericdallo14:03:51

Please open a issue so we can investigate further @U1EP3BZ3Q

ericdallo15:03:02

thanks, I took a look and commented there

genmeblog15:03:43

I see, let's move there with further discussion

genmeblog22:03:32

Just to share the conclusion from the issue: setting :notify-references-on-file-change to false solved the problem of eating CPU/RAM and hanging emacs.

ericdallo22:03:43

Good, that's a nice feature for a IDE IMO, we will focus on improve that, thank you!

ericdallo01:03:55

FYI @U1EP3BZ3Q: @U07M2C8TT’s fix was merged to master, you should be able to safely enable :notify-references-on-file-change again, let us know if notice any other performance issues

genmeblog13:03:02

Quick check and looks good! Thank you for your effort.