runtime_events_tools icon indicating copy to clipboard operation
runtime_events_tools copied to clipboard

Olly reports incorrect GC overhead time

Open tmcgilchrist opened this issue 1 year ago • 0 comments

The field GC overhead (% of CPU time) varies more than it should, ranging from 24.44% to 9446.93%. The same run of stress.exe from solver-service with 6 cores has yielded values in the range of24.44% 9446.93%. This is caused by a varying value of CPU time reported as 314.89 0.80 respectively.

$ olly gc-stats './_build/default/stress/stress.exe local --cache-dir=./cache --count=10 --internal-workers=6'
Solved warm-up requests in: 36.81s
Running another 10 solves...
10/10 complete
Solved 10 requests in 29.36s (2.94s/iter) (5.45 solves/s)

Execution times:
Wall time (s):	66.19
CPU time (s):	314.89
GC time (s):	76.96
GC overhead (% of CPU time):	24.44%

GC time per domain (s):
Domain0: 	1.95
Domain1: 	12.81
Domain2: 	12.74
Domain3: 	12.58
Domain4: 	12.34
Domain5: 	12.09
Domain6: 	12.45

GC latency profile:
#[Mean (ms):	0.19,	 Stddev (ms):	0.94]
#[Min (ms):	0.00,	 max (ms):	88.87]

Percentile 	 Latency (ms)
25.0000 	 0.00
50.0000 	 0.00
60.0000 	 0.18
70.0000 	 0.21
75.0000 	 0.22
80.0000 	 0.24
85.0000 	 0.26
90.0000 	 0.30
95.0000 	 0.41
96.0000 	 0.48
97.0000 	 0.64
98.0000 	 1.08
99.0000 	 2.29
99.9000 	 11.76
99.9900 	 31.24
99.9990 	 61.73
99.9999 	 88.87
100.0000 	 88.87
$ olly gc-stats './_build/default/stress/stress.exe local --cache-dir=./cache --count=10 --internal-workers=6'
Solved warm-up requests in: 35.92s
Running another 10 solves...
10/10 complete
Solved 10 requests in 29.82s (2.98s/iter) (5.37 solves/s)

Execution times:
Wall time (s):	65.72
CPU time (s):	0.80
GC time (s):	75.37
GC overhead (% of CPU time):	9446.93%

GC time per domain (s):
Domain0: 	1.83
Domain1: 	12.56
Domain2: 	12.46
Domain3: 	12.44
Domain4: 	12.09
Domain5: 	12.06
Domain6: 	11.93

GC latency profile:
#[Mean (ms):	0.19,	 Stddev (ms):	0.89]
#[Min (ms):	0.00,	 max (ms):	106.89]

Percentile 	 Latency (ms)
25.0000 	 0.00
50.0000 	 0.00
60.0000 	 0.18
70.0000 	 0.21
75.0000 	 0.23
80.0000 	 0.24
85.0000 	 0.26
90.0000 	 0.30
95.0000 	 0.41
96.0000 	 0.48
97.0000 	 0.63
98.0000 	 1.08
99.0000 	 2.37
99.9000 	 10.68
99.9900 	 25.23
99.9990 	 81.26
99.9999 	 106.89
100.0000 	 106.89

tmcgilchrist avatar Feb 12 '24 04:02 tmcgilchrist