clojure-dev

Issues: https://clojure.atlassian.net/browse/CLJ | Guide: https://insideclojure.org/2015/05/01/contributing-clojure/
2020-02-27T21:59:49.095400Z

I will do some more checking to verify what is going on, but I'm using criterium to benchmark some single-threaded code, and seeing 400% CPU utilization reported, and I believe there is very little GC time going on. I know that if there were a lot of GC going on, that can take advantage of multiple threads and CPU cores, so perhaps the root cause of what I am seeing is GC time that isn't reported in my current reporting of GC time. Just curious if other than GC, folks know why this might be happening.

2020-02-27T22:10:02.098200Z

I used the Ctrl-\ trick in the terminal where the JVM was running to dump thread details, and it appears there are 8 GC threads that are getting significant CPU time when I sampled the process twice about 10 seconds apart, while macOS's Activity Monitor was reporting 300 to 400% CPU utilization for the JVM process that entire 10 seconds. So looks like whatever I am using to report GC time is not counting that. I am using the JVM's GarbageCollectorMXBean API to get GC time, so it is a bit disappointing if it is leaving all of this significant GC time unreported.

2020-02-27T22:11:54.098800Z

Curious if anyone knows of a better way to get GC time/counts from within a JVM process that would include that time.

seancorfield 2020-02-27T22:14:59.100Z

Activity Monitor is weird. It always reports things as the sum of the % on each CPU so it can be up to "800%" on an 8 core box. Most things sensibly report % cpu in terms of total capacity.

jumar 2020-02-28T12:37:22.106800Z

This is a pretty normal behavior

seancorfield 2020-02-27T22:15:29.100600Z

So 25% cpu reported by the JVM can be 400% cpu reported by Activity Monitor 😞

2020-02-27T22:18:29.101400Z

Ubuntu Linux 'top' also reports %CPU > 100 on multi-core machine, similar to Activity Monitor. Repeating my experiments on Linux in case there are any noticeable differences.

2020-02-27T22:19:07.102300Z

I don't think I am using anything in the JVM to report %cpu measurements, only "time spend doing GC", which is very near 0

seancorfield 2020-02-27T22:19:11.102500Z

htop is a more useful tool than top, or so folks keep telling me...

2020-02-27T22:22:11.103900Z

htop on Linux is showing me separate lines for each JVM thread, which is nice, and separate %cpu numbers for each, but also reporting a total that is > 100%cpu for the process as a whole, which I'm assuming is using more than 1 CPU core full time, on average. In line with same total number reported by top for total CPU time of the JVM process as a whole.

2020-02-27T22:23:28.105300Z

The main thing that seems poorly reported here is the GarbageCollectorMXBean JVM API for telling me how much total time is spent in GC is often saying 0, for many seconds in a row, while 2 to 4 cores are fully pegged, and Ctrl-\ says GC threads are using very much larger than 0 CPU time.

alexmiller 2020-02-27T22:23:29.105400Z

seems like this discussion should be in #java not #clojure-dev

2020-02-27T22:23:34.105700Z

Sure, sorry.

alexmiller 2020-02-27T22:23:45.106Z

so I can not pay attention to it :)

😂 1