-
Notifications
You must be signed in to change notification settings - Fork 54
/
GCTelemetry.jsm
246 lines (203 loc) · 7.27 KB
/
GCTelemetry.jsm
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
/* -*- js-indent-level: 2; indent-tabs-mode: nil -*- */
/* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
"use strict";
/**
* This module records detailed timing information about selected
* GCs. The data is sent back in the telemetry session ping. To avoid
* bloating the ping, only a few GCs are included. There are two
* selection strategies. We always save the two GCs with the worst
* max_pause time. Additionally, two collections are selected at
* random. If a GC runs for C milliseconds and the total time for all
* GCs since the session began is T milliseconds, then the GC has a
* 2*C/T probablility of being selected (the factor of 2 is because we
* save two of them).
*
* GCs from both the main process and all content processes are
* recorded. The data is cleared for each new subsession.
*/
ChromeUtils.import("resource://gre/modules/Services.jsm", this);
const {Log} = ChromeUtils.import("resource://gre/modules/Log.jsm");
var EXPORTED_SYMBOLS = ["GCTelemetry"];
// Names of processes where we record GCs.
const PROCESS_NAMES = ["main", "content"];
// Should be the time we started up in milliseconds since the epoch.
const BASE_TIME = Date.now() - Services.telemetry.msSinceProcessStart();
// Records selected GCs. There is one instance per process type.
class GCData {
constructor(kind) {
let numRandom = {main: 0, content: 2};
let numWorst = {main: 2, content: 2};
this.totalGCTime = 0;
this.randomlySelected = Array(numRandom[kind]).fill(null);
this.worst = Array(numWorst[kind]).fill(null);
}
// Turn absolute timestamps (in microseconds since the epoch) into
// milliseconds since startup.
rebaseTimes(data) {
function fixup(t) {
return t / 1000.0 - BASE_TIME;
}
data.timestamp = fixup(data.timestamp);
for (let i = 0; i < data.slices_list.length; i++) {
let slice = data.slices_list[i];
slice.start_timestamp = fixup(slice.start_timestamp);
// Slices have no end_timestamp, instead they have a duration.
}
}
// Records a GC (represented by |data|) in the randomlySelected or
// worst batches depending on the criteria above.
record(data) {
this.rebaseTimes(data);
let time = data.total_time;
this.totalGCTime += time;
// Probability that we will replace any one of our
// current randomlySelected GCs with |data|.
let prob = time / this.totalGCTime;
// Note that we may replace multiple GCs in
// randomlySelected. It's easier to reason about the
// probabilities this way, and it's unlikely to have any effect in
// practice.
for (let i = 0; i < this.randomlySelected.length; i++) {
let r = Math.random();
if (r <= prob) {
this.randomlySelected[i] = data;
}
}
// Save the 2 worst GCs based on max_pause. A GC may appear in
// both worst and randomlySelected.
for (let i = 0; i < this.worst.length; i++) {
if (!this.worst[i]) {
this.worst[i] = data;
break;
}
if (this.worst[i].max_pause < data.max_pause) {
this.worst.splice(i, 0, data);
this.worst.length--;
break;
}
}
}
entries() {
return {
random: this.randomlySelected.filter(e => e !== null),
worst: this.worst.filter(e => e !== null),
};
}
}
// If you adjust any of the constants here (slice limit, number of keys, etc.)
// make sure to update the JSON schema at:
// https://github.com/mozilla-services/mozilla-pipeline-schemas/blob/master/telemetry/main.schema.json
// You should also adjust browser_TelemetryGC.js.
const MAX_GC_KEYS = 24;
const MAX_SLICES = 4;
const MAX_SLICE_KEYS = 12;
const MAX_PHASES = 65;
const LOGGER_NAME = "Toolkit.Telemetry";
function limitProperties(name, obj, count, log) {
// If there are too many properties delete all/most of them. We don't
// expect this ever to happen.
let num_properties = Object.keys(obj).length;
if (num_properties > count) {
for (let key of Object.keys(obj)) {
// If this is the main GC object then save some of the critical
// properties.
if (name === "data" && (
key === "max_pause" ||
key === "slices" ||
key === "slices_list" ||
key === "status" ||
key === "timestamp" ||
key === "total_time" ||
key === "totals")) {
continue;
}
delete obj[key];
}
let log_fn;
if ((name === "slice.times") || (name === "data.totals")) {
// This is a bit more likely, but is mostly-okay.
log_fn = s => log.info(s);
} else {
log_fn = s => log.warn(s);
}
log_fn(`Number of properties exceeded in the GC telemetry ${name} ping, expected ${count} got ${num_properties}`);
}
}
/*
* Reduce the size of the object by limiting the number of slices or times
* etc.
*/
function limitSize(data, log) {
data.slices_list.sort((a, b) => b.pause - a.pause);
if (data.slices_list.length > MAX_SLICES) {
// Make sure we always keep the first slice since it has the
// reason the GC was started.
let firstSliceIndex = data.slices_list.findIndex(s => s.slice == 0);
if (firstSliceIndex >= MAX_SLICES) {
data.slices_list[MAX_SLICES - 1] = data.slices_list[firstSliceIndex];
}
data.slices_list.length = MAX_SLICES;
}
data.slices_list.sort((a, b) => a.slice - b.slice);
limitProperties("data", data, MAX_GC_KEYS, log);
for (let slice of data.slices_list) {
limitProperties("slice", slice, MAX_SLICE_KEYS, log);
limitProperties("slice.times", slice.times, MAX_PHASES, log);
}
limitProperties("data.totals", data.totals, MAX_PHASES, log);
}
let processData = new Map();
for (let name of PROCESS_NAMES) {
processData.set(name, new GCData(name));
}
var GCTelemetry = {
initialized: false,
init() {
if (this.initialized) {
return false;
}
this.initialized = true;
this._log = Log.repository.getLoggerWithMessagePrefix(
LOGGER_NAME, "GCTelemetry::");
Services.obs.addObserver(this, "garbage-collection-statistics");
if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_DEFAULT) {
Services.ppmm.addMessageListener("Telemetry:GCStatistics", this);
}
return true;
},
shutdown() {
if (!this.initialized) {
return;
}
Services.obs.removeObserver(this, "garbage-collection-statistics");
if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_DEFAULT) {
Services.ppmm.removeMessageListener("Telemetry:GCStatistics", this);
}
this.initialized = false;
},
observe(subject, topic, arg) {
this.observeRaw(JSON.parse(arg));
},
// We expose this method so unit tests can call it, no need to test JSON
// parsing.
observeRaw(data) {
limitSize(data, this._log);
if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_DEFAULT) {
processData.get("main").record(data);
} else {
Services.cpmm.sendAsyncMessage("Telemetry:GCStatistics", data);
}
},
receiveMessage(msg) {
processData.get("content").record(msg.data);
},
entries(kind, clear) {
let result = processData.get(kind).entries();
if (clear) {
processData.set(kind, new GCData(kind));
}
return result;
},
};