Bug 882968 - high cpu consumption by multi threaded GC. Option -XX:+UseSerialGC fixes the problem.
Summary: high cpu consumption by multi threaded GC. Option -XX:+UseSerialGC fixes th...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: java-1.7.0-openjdk
Version: 23
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Andrew Haley
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-12-03 14:10 UTC by Need Real Name
Modified: 2016-02-03 11:29 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-02-03 11:29:43 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Icedtea Bugzilla 1222 0 None None None Never

Description Need Real Name 2012-12-03 14:10:58 UTC
Fedora java have the following problem
I have a big unit test (>500 classes)
all tests are single threaded deterministic numerical 
calculations and java collection data structure manipulation.
Garbage collector load is very moderate.

The computer is 4 core Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
which Linux sees as 8 cpu.

The problem:

When I start unit test eventually I get 
very high CPU consumption on all of few started jdks.
e.g.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
29838 mal       20   0 9808m 3.3g   9m S 548.7 10.6   1026:44 java              
29839 mal       20   0 9808m 1.6g   9m S 99.7  5.2 682:16.81 java               
30504 mal       20   0 9804m  24m 9960 S 74.8  0.1   1:09.40 javac              
28459 mal       20   0 9808m 1.6g 7912 S 72.8  5.1   1341:47 java      

While this lasts (>100% CPU) 
the computer becomes non-responsive 
and it takes minutes just to 
compile something with javac 
or even to show options
java -h

When cpu usage on that process goes down to 100% everything becomes OK.
Previously any jdk process typically 
consumed about 100% cpu and everything was OK.

Some changes, possible in linux kernel or jdk 
caused this high CPU on some process 
 another example

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
27676 mal       20   0 9872m 3.6g 8468 S 377.3 11.6   1441:27 java              
27677 mal       20   0 9808m 3.3g 8472 S 367.4 10.6   1547:49 java              
28459 mal       20   0 9808m  53m 7820 S 49.4  0.2 415:32.12 java               
14755 root      20   0     0    0    0 S  2.0  0.0   0:23.74 kworker/3:1        
    1 root      20   0 69084 4320 1732 S  0.0  0.0   0:03.48 systemd            
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.28 kthreadd     



The problem was not noticed in around August 2012.
Currently it was reproduced on:
 
java -version
java version "1.7.0_09-icedtea"
OpenJDK Runtime Environment (fedora-2.3.3.fc17.1-x86_64)
OpenJDK 64-Bit Server VM (build 23.2-b09, mixed mode)

 java -version
java version "1.6.0_35"
Java(TM) SE Runtime Environment (build 1.6.0_35-b10)
Java HotSpot(TM) 64-Bit Server VM (build 20.10-b01, mixed mode)

 java -version
java version "1.7.0_09"
Java(TM) SE Runtime Environment (build 1.7.0_09-b05)
Java HotSpot(TM) 64-Bit Server VM (build 23.5-b02, mixed mode)

How can I get back, how it used to be:
A jdk with full load consumes about 100% CPU
and goes up to 110-120% during garbage collection activity.

Comment 1 Need Real Name 2012-12-03 15:28:05 UTC
typical -verbosegc activity

[GC 205164K->88888K(529792K), 0.0322330 secs]
[GC 256952K->111116K(563456K), 0.0326090 secs]
[GC 312844K->99364K(592128K), 0.0111930 secs]
[GC 341476K->102581K(643776K), 0.0101070 secs]
[GC 393141K->106848K(715264K), 0.0118210 secs]
[GC 448096K->99468K(724480K), 0.0086280 secs]
[GC 449996K->127873K(722624K), 0.0199200 secs]
[GC 478401K->96847K(800192K), 0.0053250 secs]
[GC 517519K->120997K(800384K), 0.0227900 secs]
[GC 541669K->136976K(879168K), 9.7114270 secs]
[GC 634640K->133554K(886336K), 15.3138190 secs]
[GC 631218K->121857K(988800K), 55.5103740 secs]
[GC 719105K->113634K(989632K), 16.8052030 secs]
[GC 710882K->115767K(1100416K), 142.1581620 secs]
[GC 832503K->121082K(1103296K), 32.7212000 secs]
[GC 837818K->100876K(1246080K), 26.8942670 secs]
[GC 960972K->131807K(1246080K), 158.6862940 secs]
[GC 991903K->97159K(1421440K), 20.1908390 secs]
[GC 1128967K->139502K(1421760K), 179.5423220 secs]
[GC 1171310K->98999K(1633344K), 0.0037880 secs]

Comment 2 Need Real Name 2012-12-03 19:50:05 UTC
looks like the option
 -XX:+UseSerialGC
cures the issue.
Looks like multi-thead GC is unusable on Linux x64

Comment 3 Need Real Name 2012-12-03 20:47:34 UTC
Typical memory/CPU usage for -XX:+UseSerialGC option
so much better better than the defaults.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
 7921 mal       20   0 8942m 554m 9.9m S 99.8  1.7  15:34.95 java               
 7920 mal       20   0 8942m 584m 9.9m S 99.5  1.8  15:35.57 java       

Almost no spikes >120% CPU.
The 120-130% CPU usage goes for less than a second (single thread GC activity).
Than back to 100% as expected, when GC is not active.

The multi thread GC is definitely broken on Linux x64.
I was not able to run just 3 unit tests at once at 3.4 Ghz 32Gb memory computer.

Comment 4 Need Real Name 2012-12-03 22:33:41 UTC
Also, note memory usage by programs when multi-threaded GC is used.
There is no way the unit tests can consume 
3.3 Gbytes of memory.
Most likely leakage in multi-threaded GC.
I will wait what single threaded GC would show, 
but it expect should never exceed 0.2-0.5Gb.

Comment 5 Need Real Name 2012-12-04 13:21:02 UTC
Some time later.
memory usage with single threaded GC is still lower than with multi threaded GC,
what may be an indication of memory leak in multi threaded GC 
(in addition to high CPU consumption).

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
 7921 mal       20   0 8949m 650m  10m S 100.1  2.0   1005:28 java              
 7920 mal       20   0 8942m 605m  10m S 99.4  1.9   1005:27 java     

Also, the issue is may well be glibc related.
Because I do not remember this issue back in August 2012 with java6.
It may be some strange interaction between glibc and java.

Comment 6 Need Real Name 2012-12-04 17:07:14 UTC
More time later. Again, no memory footprint increase. 
Still about 2% usage, not 10% as it was when multi-thread GC was used. 

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
 7920 mal       20   0 8942m 606m  10m S 99.7  1.9   1233:46 java               
 7921 mal       20   0 8949m 651m  10m S 99.7  2.0   1233:48 java

Comment 7 Need Real Name 2012-12-04 18:17:34 UTC
By the way.
when javac is invoked it may consume >500% CPU
because javac uses multi-threaded GC by default.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
16947 mal       20   0 9804m 141m  10m S 502.7  0.4   0:19.86 javac             
 7921 mal       20   0 8949m 651m  10m S 85.1  2.0   1304:06 java               
 7920 mal       20   0 8942m 606m  10m S 76.1  1.9   1304:05 java

Comment 8 Need Real Name 2012-12-08 06:23:10 UTC
just on compiler stage.
javac consumes all the CPU and it takes 5 minutes to compile a trivial program.

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
13234 mal       20   0 9804m 143m  10m S 738.4  0.5  11:41.04 javac

Comment 9 Need Real Name 2012-12-08 06:28:29 UTC
I am not completely sure, but looks that
javac -g -J-XX:+UseSerialGC file.java
does not cause this all the CPU consumption by javac problem.

Comment 10 Need Real Name 2012-12-12 21:42:06 UTC
confirmed that this option:
javac -g -J-XX:+UseSerialGC file.java

cause no single high CPU consumption case by javac.
without -J-XX:+UseSerialGC 
once in a while it takes >5 min
to compile a trivial program.

Comment 11 Fedora End Of Life 2013-12-21 15:13:33 UTC
This message is a reminder that Fedora 18 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 18. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '18'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 18's end of life.

Thank you for reporting this issue and we are sorry that we may not be 
able to fix it before Fedora 18 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior to Fedora 18's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 12 Jan Kurik 2015-07-15 14:55:39 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 23 development cycle.
Changing version to '23'.

(As we did not run this process for some time, it could affect also pre-Fedora 23 development
cycle bugs. We are very sorry. It will help us with cleanup during Fedora 23 End Of Life. Thank you.)

More information and reason for this action is here:
https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora23


Note You need to log in before you can comment on or make changes to this bug.