1 /*
2 * Copyright (c) 2021 Huawei Device Co., Ltd.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at
6 *
7 * http://www.apache.org/licenses/LICENSE-2.0
8 *
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
14 */
15
16 #include "ecmascript/mem/gc_stats.h"
17
18 #include "ecmascript/mem/heap.h"
19 #include "ecmascript/mem/mem.h"
20
21 namespace panda::ecmascript {
PrintStatisticResult(bool force)22 void GCStats::PrintStatisticResult(bool force)
23 {
24 LOG_GC(INFO) << "/******************* GCStats statistic: *******************/";
25 PrintSemiStatisticResult(force);
26 PrintPartialStatisticResult(force);
27 PrintCompressStatisticResult(force);
28 PrintHeapStatisticResult(force);
29 }
30
PrintSemiStatisticResult(bool force)31 void GCStats::PrintSemiStatisticResult(bool force)
32 {
33 if ((force && semiGCCount_ != 0) || (!force && semiGCCount_ != lastSemiGCCount_)) {
34 lastSemiGCCount_ = semiGCCount_;
35 LOG_GC(INFO) << " STWYoungGC statistic: total semi gc count " << semiGCCount_;
36 LOG_GC(INFO) << " MIN pause time: " << PrintTimeMilliseconds(semiGCMinPause_) << "ms"
37 << " MAX pause time: " << PrintTimeMilliseconds(semiGCMaxPause_) << "ms"
38 << " total pause time: " << PrintTimeMilliseconds(semiGCTotalPause_) << "ms"
39 << " average pause time: " << PrintTimeMilliseconds(semiGCTotalPause_ / semiGCCount_)
40 << "ms"
41 << " tatal alive size: " << sizeToMB(semiTotalAliveSize_) << "MB"
42 << " average alive size: " << sizeToMB(semiTotalAliveSize_ / semiGCCount_) << "MB"
43 << " tatal commit size: " << sizeToMB(semiTotalCommitSize_) << "MB"
44 << " average commit size: " << sizeToMB(semiTotalCommitSize_ / semiGCCount_) << "MB"
45 << " semi aliveRate: " << double(semiTotalAliveSize_) / semiTotalCommitSize_
46 << " total promote size: " << sizeToMB(semiTotalPromoteSize_) << "MB"
47 << " average promote size: " << sizeToMB(semiTotalPromoteSize_ / semiGCCount_) << "MB";
48 }
49 }
50
PrintPartialStatisticResult(bool force)51 void GCStats::PrintPartialStatisticResult(bool force)
52 {
53 if ((force && partialGCCount_ != 0) || (!force && lastOldGCCount_ != partialGCCount_)) {
54 lastOldGCCount_ = partialGCCount_;
55 LOG_GC(INFO) << " PartialGC with non-concurrent mark statistic: total old gc count " << partialGCCount_;
56 LOG_GC(INFO) << " Pause time statistic:: MIN pause time: " << PrintTimeMilliseconds(partialGCMinPause_)
57 << "ms"
58 << " MAX pause time: " << PrintTimeMilliseconds(partialGCMaxPause_) << "ms"
59 << " total pause time: " << PrintTimeMilliseconds(partialGCTotalPause_) << "ms"
60 << " average pause time: " << PrintTimeMilliseconds(partialGCTotalPause_ / partialGCCount_)
61 << "ms";
62 if (!force) {
63 PrintHeapStatisticResult(true);
64 }
65 }
66
67 if ((force && partialConcurrentMarkGCCount_ != 0) ||
68 (!force && lastOldConcurrentMarkGCCount_ != partialConcurrentMarkGCCount_)) {
69 lastOldConcurrentMarkGCCount_ = partialConcurrentMarkGCCount_;
70 LOG_GC(INFO) << " PartialCollector with concurrent mark statistic: total old gc count "
71 << partialConcurrentMarkGCCount_;
72 LOG_GC(INFO) << " Pause time statistic:: Current GC pause time: "
73 << PrintTimeMilliseconds(partialConcurrentMarkGCPauseTime_) << "ms"
74 << " Concurrent mark pause time: " << PrintTimeMilliseconds(partialConcurrentMarkMarkPause_)
75 << "ms"
76 << " Concurrent mark wait time: " << PrintTimeMilliseconds(partialConcurrentMarkWaitPause_)
77 << "ms"
78 << " Remark pause time: " << PrintTimeMilliseconds(partialConcurrentMarkRemarkPause_)
79 << "ms"
80 << " Evacuate pause time: " << PrintTimeMilliseconds(partialConcurrentMarkEvacuatePause_)
81 << "ms"
82 << " MIN pause time: " << PrintTimeMilliseconds(partialConcurrentMarkGCMinPause_) << "ms"
83 << " MAX pause time: " << PrintTimeMilliseconds(partialConcurrentMarkGCMaxPause_) << "ms"
84 << " total pause time: " << PrintTimeMilliseconds(partialConcurrentMarkGCTotalPause_)
85 << "ms"
86 << " average pause time: "
87 << PrintTimeMilliseconds(partialConcurrentMarkGCTotalPause_ / partialConcurrentMarkGCCount_)
88 << "ms";
89 if (!force) {
90 PrintHeapStatisticResult(true);
91 }
92 }
93 }
94
PrintCompressStatisticResult(bool force)95 void GCStats::PrintCompressStatisticResult(bool force)
96 {
97 if ((force && fullGCCount_ != 0) || (!force && fullGCCount_ != lastFullGCCount_)) {
98 lastFullGCCount_ = fullGCCount_;
99 LOG_GC(INFO) << " FullGC statistic: total compress gc count " << fullGCCount_;
100 LOG_GC(INFO)
101 << " MIN pause time: " << PrintTimeMilliseconds(fullGCMinPause_) << "ms"
102 << " MAX pause time: " << PrintTimeMilliseconds(fullGCMaxPause_) << "ms"
103 << " total pause time: " << PrintTimeMilliseconds(fullGCTotalPause_) << "ms"
104 << " average pause time: " << PrintTimeMilliseconds(fullGCTotalPause_ / fullGCCount_) << "ms"
105 << " young and old total alive size: " << sizeToMB(compressYoungAndOldAliveSize_) << "MB"
106 << " young and old average alive size: " << sizeToMB(compressYoungAndOldAliveSize_ / fullGCCount_)
107 << "MB"
108 << " young total commit size: " << sizeToMB(compressYoungCommitSize_) << "MB"
109 << " old total commit size: " << sizeToMB(compressOldCommitSize_) << "MB"
110 << " young and old average commit size: "
111 << sizeToMB((compressYoungCommitSize_ + compressOldCommitSize_) / fullGCCount_) << "MB"
112 << " young and old free rate: "
113 << 1 - float(compressYoungAndOldAliveSize_) / (compressYoungCommitSize_ + compressOldCommitSize_)
114 << " non move total free size: " << sizeToMB(compressNonMoveTotalFreeSize_) << "MB"
115 << " non move total commit size: " << sizeToMB(compressNonMoveTotalCommitSize_) << "MB"
116 << " non move free rate: " << float(compressNonMoveTotalFreeSize_) / compressNonMoveTotalCommitSize_;
117 }
118 }
119
PrintHeapStatisticResult(bool force)120 void GCStats::PrintHeapStatisticResult(bool force)
121 {
122 if (force && heap_ != nullptr) {
123 NativeAreaAllocator *nativeAreaAllocator = heap_->GetNativeAreaAllocator();
124 HeapRegionAllocator *heapRegionAllocator = heap_->GetHeapRegionAllocator();
125 LOG_GC(INFO) << "/******************* Memory statistic: *******************/";
126 LOG_GC(INFO) << " Anno memory usage size: " << sizeToMB(heapRegionAllocator->GetAnnoMemoryUsage())
127 << "MB"
128 << " anno memory max usage size: " << sizeToMB(heapRegionAllocator->GetMaxAnnoMemoryUsage())
129 << "MB"
130 << " native memory usage size: " << sizeToMB(nativeAreaAllocator->GetNativeMemoryUsage())
131 << "MB"
132 << " native memory max usage size: "
133 << sizeToMB(nativeAreaAllocator->GetMaxNativeMemoryUsage()) << "MB";
134 LOG_GC(INFO) << " Semi space commit size: " << sizeToMB(heap_->GetNewSpace()->GetCommittedSize()) << "MB"
135 << " semi space heap object size: " << sizeToMB(heap_->GetNewSpace()->GetHeapObjectSize())
136 << "MB"
137 << " old space commit size: "
138 << sizeToMB(heap_->GetOldSpace()->GetCommittedSize()) << "MB"
139 << " old space heap object size: " << sizeToMB(heap_->GetOldSpace()->GetHeapObjectSize())
140 << "MB"
141 << " non move space commit size: "
142 << sizeToMB(heap_->GetNonMovableSpace()->GetCommittedSize()) << "MB"
143 << " huge object space commit size: "
144 << sizeToMB(heap_->GetHugeObjectSpace()->GetCommittedSize()) << "MB"
145 << ", AppSpawn space commit size: "
146 << sizeToMB(heap_->GetAppSpawnSpace()->GetCommittedSize()) << "MB";
147 }
148 }
149
StatisticSTWYoungGC(Duration time,size_t aliveSize,size_t promotedSize,size_t commitSize)150 void GCStats::StatisticSTWYoungGC(Duration time, size_t aliveSize, size_t promotedSize, size_t commitSize)
151 {
152 auto timeInMS = TimeToMicroseconds(time);
153 if (semiGCCount_ == 0) {
154 semiGCMinPause_ = timeInMS;
155 semiGCMaxPause_ = timeInMS;
156 } else {
157 semiGCMinPause_ = std::min(semiGCMinPause_, timeInMS);
158 semiGCMaxPause_ = std::max(semiGCMaxPause_, timeInMS);
159 }
160 semiGCTotalPause_ += timeInMS;
161 semiTotalAliveSize_ += aliveSize;
162 semiTotalCommitSize_ += commitSize;
163 semiTotalPromoteSize_ += promotedSize;
164 semiGCCount_++;
165 currentGcType_ = "STWYoungGC";
166 currentPauseTime_ = timeInMS / THOUSAND;
167 }
168
StatisticPartialGC(bool concurrentMark,Duration time,size_t freeSize)169 void GCStats::StatisticPartialGC(bool concurrentMark, Duration time, size_t freeSize)
170 {
171 auto timeInMS = TimeToMicroseconds(time);
172 if (concurrentMark) {
173 timeInMS += partialConcurrentMarkMarkPause_;
174 timeInMS += partialConcurrentMarkWaitPause_;
175 if (partialConcurrentMarkGCCount_ == 0) {
176 partialConcurrentMarkGCMinPause_ = timeInMS;
177 partialConcurrentMarkGCMaxPause_ = timeInMS;
178 } else {
179 partialConcurrentMarkGCMinPause_ = std::min(partialConcurrentMarkGCMinPause_, timeInMS);
180 partialConcurrentMarkGCMaxPause_ = std::max(partialConcurrentMarkGCMaxPause_, timeInMS);
181 }
182 partialConcurrentMarkGCPauseTime_ = timeInMS;
183 partialConcurrentMarkGCTotalPause_ += timeInMS;
184 partialOldSpaceConcurrentMarkFreeSize_ = freeSize;
185 partialConcurrentMarkGCCount_++;
186 } else {
187 if (partialGCCount_ == 0) {
188 partialGCMinPause_ = timeInMS;
189 partialGCMaxPause_ = timeInMS;
190 } else {
191 partialGCMinPause_ = std::min(partialGCMinPause_, timeInMS);
192 partialGCMaxPause_ = std::max(partialGCMaxPause_, timeInMS);
193 }
194 partialGCTotalPause_ += timeInMS;
195 partialOldSpaceFreeSize_ = freeSize;
196 partialGCCount_++;
197 }
198 currentGcType_ = "PartialGC";
199 currentPauseTime_ = timeInMS / THOUSAND;
200 }
201
StatisticFullGC(Duration time,size_t youngAndOldAliveSize,size_t youngCommitSize,size_t oldCommitSize,size_t nonMoveSpaceFreeSize,size_t nonMoveSpaceCommitSize)202 void GCStats::StatisticFullGC(Duration time, size_t youngAndOldAliveSize, size_t youngCommitSize,
203 size_t oldCommitSize, size_t nonMoveSpaceFreeSize,
204 size_t nonMoveSpaceCommitSize)
205 {
206 auto timeInMS = TimeToMicroseconds(time);
207 if (fullGCCount_ == 0) {
208 fullGCMinPause_ = timeInMS;
209 fullGCMaxPause_ = timeInMS;
210 } else {
211 fullGCMinPause_ = std::min(fullGCMinPause_, timeInMS);
212 fullGCMaxPause_ = std::max(fullGCMaxPause_, timeInMS);
213 }
214 fullGCTotalPause_ += timeInMS;
215 compressYoungAndOldAliveSize_ += youngAndOldAliveSize;
216 compressYoungCommitSize_ += youngCommitSize;
217 compressOldCommitSize_ += oldCommitSize;
218 compressNonMoveTotalFreeSize_ += nonMoveSpaceFreeSize;
219 compressNonMoveTotalCommitSize_ += nonMoveSpaceCommitSize;
220 fullGCCount_++;
221 currentGcType_ = "FullGC";
222 currentPauseTime_ = timeInMS / THOUSAND;
223 }
224
CheckIfLongTimePause()225 void GCStats::CheckIfLongTimePause()
226 {
227 if (currentPauseTime_ > longPauseTime_) {
228 LOG_GC(INFO) << "Has checked a long time gc; gc type = " << currentGcType_ << "; pause time = "
229 << currentPauseTime_ << "ms";
230 LOG_GC(INFO) << "/******************* GCStats statistic: *******************/";
231 PrintSemiStatisticResult(true);
232 PrintPartialStatisticResult(true);
233 PrintCompressStatisticResult(true);
234 PrintHeapStatisticResult(true);
235 }
236 }
237
StatisticConcurrentMark(Duration time)238 void GCStats::StatisticConcurrentMark(Duration time)
239 {
240 partialConcurrentMarkMarkPause_ = TimeToMicroseconds(time);
241 }
242
StatisticConcurrentMarkWait(Duration time)243 void GCStats::StatisticConcurrentMarkWait(Duration time)
244 {
245 partialConcurrentMarkWaitPause_ = TimeToMicroseconds(time);
246 }
247
StatisticConcurrentEvacuate(Duration time)248 void GCStats::StatisticConcurrentEvacuate(Duration time)
249 {
250 partialConcurrentMarkEvacuatePause_ = TimeToMicroseconds(time);
251 }
252
StatisticConcurrentRemark(Duration time)253 void GCStats::StatisticConcurrentRemark(Duration time)
254 {
255 partialConcurrentMarkRemarkPause_ = TimeToMicroseconds(time);
256 }
257 } // namespace panda::ecmascript
258