Skip to content

Commit 7123764

Browse files
committed
add documentation for "VM operations overhead" in the "Event details" tab
1 parent 34afc1a commit 7123764

File tree

1 file changed

+55
-4
lines changed

1 file changed

+55
-4
lines changed

README.md

Lines changed: 55 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,12 @@ on his very good work.
4040
Links to detailed descriptions of many JVM parameters relevant to garbage collection
4141
can be found in the links section of https://github.com/chewiebug/GCViewer/wiki
4242

43+
Results of log analysis
44+
=======================
45+
There are two sections, where the results of the log analysis are shown.
46+
One is the left side with the chart, the other the data panel on the right side.
47+
In the following, the content of these sections is explained.
48+
4349
Chart
4450
-----
4551

@@ -77,7 +83,9 @@ GCViewer shows a number of lines etc. in a chart (first tab). These are:
7783
and pink vertical line for every end (CMS-concurrent-reset /
7884
G1: concurrent-cleanup-end) of a concurrent collection cycle
7985

80-
In the second tab ("Event details") it shows details about the events it parsed:
86+
Event details
87+
-------------
88+
In the second tab it shows details about the events it parsed:
8189
E.g. events like the following
8290

8391
24.187: [GC 24.188: [ParNew: 93184K->5464K(104832K), 0.0442895 secs] \
@@ -100,10 +108,53 @@ So for every line the text is extracted (not always every part of it). This allo
100108
a user which is familiar with the text log files to find out more details about
101109
the events that occurred.
102110

103-
Metrics
104-
=======
111+
### Gc pauses
112+
This are shows all stop-the-world pauses, that are not full gc pauses.
113+
114+
### Full gc pauses
115+
In this area all pauses are shown, which GCViewer considers as "full gc"
116+
pauses. The current definition of a "full gc" is: Either the gc algorithm
117+
prints "full gc" in its event name, or more than one generation (young,
118+
old, permgen / metaspace) were involved during collection.
119+
120+
### VM operations overhead (safepoint pauses)
121+
This area is only shown, if the gc log was written with the option
122+
-XX:+PrintGCApplicationStoppedTime. To understand the meaning of this
123+
metric, it is important to know about safepoints (see e.g.
124+
http://blog.ragozin.info/2012/10/safepoints-in-hotspot-jvm.html).
125+
126+
If GCViewer finds gc log lines like the following:
127+
2017-03-29T14:37:12.812+0200: 8.832: [GC (Allocation Failure) \
128+
[PSYoungGen: 29146K->3457K(29184K)] 78228K->52539K(116736K), 0.0009340 secs] \
129+
[Times: user=0.00 sys=0.00, real=0.00 secs]
130+
2017-03-29T14:37:12.813+0200: 8.833: Total time for which application \
131+
threads were stopped: 0.0010682 seconds, Stopping threads took: 0.0000155 seconds
132+
133+
GCViewer will report one event in the "Gc pauses" area and one in this area.
134+
The pause duration reported for "Total time..." will be 0.0001342s
135+
(0.0010682 (duration of safepoint pause) - 0.0009340 (duration of gc pause))
136+
So GCViewer only calculates the additional overhead needed for the whole
137+
safepoint on top of the gc pause.
138+
139+
If the event immediately before the "Total time..." event was not a any
140+
kind of gc pause, but another "Total time..." event, then the whole pause
141+
for "Total time..." will be recorded for this event. In this case the
142+
safepoint was not caused by a gc pause.
143+
144+
### Concurrent GCs
145+
This are contains information about concurrent collection cycles, if
146+
the gc algorithm used them. The time reported here is spent while the
147+
application threads are running. It is possible to read here, how long
148+
concurrent gc operations took until they finished.
149+
150+
Parser
151+
------
152+
In the third tab the output of the parser is shown. If there were warnings
153+
during the parsing process or other output, you can check there.
105154

106-
GCViewer provides some metrics to help you interpret the graph.
155+
Data Panel
156+
==========
157+
GCViewer provides some metrics to help you interpret the chart.
107158
Note that some metrics based on averages are shown along with
108159
their standard deviation. If it is obvious that the standard
109160
deviation is fairly big in comparison to the average, the values

0 commit comments

Comments
 (0)