Hi,
I get an issue where, when I'm deleting and adding Solr cores, it appears to go
into a loop increasing CPU load and continually (every 2 seconds) logging to the
garbage collection log.
I had this problem with 6.1.0 so we've just upgraded to 6.4.1 and the issue
still occurs. The entries being logged every 2 seconds are below (hope it's not
too verbose). Obviously this means the log gets big quickly.
We can work around the issue by restarting Solr but presumably something has
gone wrong. Can anyone suggest if we're doing something incorrectly to cause
this, or if it's an issue we can troubleshoot.
Any advice gratefully received.
On CentOS 7 with OpenJDK 1.8.0_91-b14.
solr_gc.log.0.current logs the following every 2 seconds:
2017-02-13T16:19:11.230+0000: 5092.640: [GC (CMS Initial Mark) [1
CMS-initial-mark: 225270K(393216K)] 225280K(502464K), 0.0030517 secs] [Times:
user=0.01 sys=0.00, real=0.01 secs]
2017-02-13T16:19:11.234+0000: 5092.643: Total time for which application threads
were stopped: 0.0033800 seconds, Stopping threads took: 0.0000473 seconds
2017-02-13T16:19:11.234+0000: 5092.643: [CMS-concurrent-mark-start]
2017-02-13T16:19:11.359+0000: 5092.769: [CMS-concurrent-mark: 0.125/0.125 secs]
[Times: user=0.50 sys=0.00, real=0.12 secs]
2017-02-13T16:19:11.359+0000: 5092.769: [CMS-concurrent-preclean-start]
2017-02-13T16:19:11.361+0000: 5092.771: [CMS-concurrent-preclean: 0.002/0.002
secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-02-13T16:19:11.362+0000: 5092.771: [GC (CMS Final Remark) [YG occupancy: 10
K (109248 K)]{Heap before GC invocations=3236 (full 1150):
par new generation total 109248K, used 10K [0x00000000e0000000,
0x00000000e8000000, 0x00000000e8000000)
eden space 87424K, 0% used [0x00000000e0000000, 0x00000000e0001020,
0x00000000e5560000)
from space 21824K, 0% used [0x00000000e6ab0000, 0x00000000e6ab1830,
0x00000000e8000000)
to space 21824K, 0% used [0x00000000e5560000, 0x00000000e5560000,
0x00000000e6ab0000)
concurrent mark-sweep generation total 393216K, used 225270K
[0x00000000e8000000, 0x0000000100000000, 0x0000000100000000)
Metaspace used 176850K, capacity 179580K, committed 181092K, reserved 1210368K
class space used 18794K, capacity 19506K, committed 19836K, reserved 1048576K
2017-02-13T16:19:11.362+0000: 5092.771: [GC (CMS Final Remark)
2017-02-13T16:19:11.362+0000: 5092.771: [ParNew
Desired survivor size 20112992 bytes, new threshold 8 (max 8)
- age 2: 160 bytes, 160 total
- age 4: 32 bytes, 192 total
: 10K->6K(109248K), 0.0041872 secs] 225280K->225276K(502464K), 0.0042455 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
Heap after GC invocations=3237 (full 1150):
par new generation total 109248K, used 6K [0x00000000e0000000,
0x00000000e8000000, 0x00000000e8000000)
eden space 87424K, 0% used [0x00000000e0000000, 0x00000000e0000000,
0x00000000e5560000)
from space 21824K, 0% used [0x00000000e5560000, 0x00000000e5561830,
0x00000000e6ab0000)
to space 21824K, 0% used [0x00000000e6ab0000, 0x00000000e6ab0000,
0x00000000e8000000)
concurrent mark-sweep generation total 393216K, used 225270K
[0x00000000e8000000, 0x0000000100000000, 0x0000000100000000)
Metaspace used 176850K, capacity 179580K, committed 181092K, reserved 1210368K
class space used 18794K, capacity 19506K, committed 19836K, reserved 1048576K
}
2017-02-13T16:19:11.366+0000: 5092.775: [Rescan (parallel) , 0.0018980
secs]2017-02-13T16:19:11.368+0000: 5092.777: [weak refs processing, 0.0004940
secs]2017-02-13T16:19:11.368+0000: 5092.778: [class unloading, 0.0580950
secs]2017-02-13T16:19:11.426+0000: 5092.836: [scrub symbol table, 0.0110875
secs]2017-02-13T16:19:11.438+0000: 5092.847: [scrub string table, 0.0019072
secs][1 CMS-remark: 225270K(393216K)] 225276K(502464K), 0.0780250 secs] [Times:
user=0.09 sys=0.00, real=0.08 secs]
2017-02-13T16:19:11.440+0000: 5092.849: Total time for which application threads
were stopped: 0.0782677 seconds, Stopping threads took: 0.0000411 seconds
2017-02-13T16:19:11.440+0000: 5092.849: [CMS-concurrent-sweep-start]
2017-02-13T16:19:11.546+0000: 5092.955: [CMS-concurrent-sweep: 0.106/0.106 secs]
[Times: user=0.11 sys=0.00, real=0.11 secs]
2017-02-13T16:19:11.546+0000: 5092.955: [CMS-concurrent-reset-start]
2017-02-13T16:19:11.546+0000: 5092.956: [CMS-concurrent-reset: 0.001/0.001 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
Regards,
Leon Stringer
