1 | // Copyright (C) 2016 The Qt Company Ltd. |
2 | // SPDX-License-Identifier: LicenseRef-Qt-Commercial OR GPL-3.0-only WITH Qt-GPL-exception-1.0 |
3 | |
4 | #include "qmlprofilerdata.h" |
5 | |
6 | #include <QStringList> |
7 | #include <QUrl> |
8 | #include <QHash> |
9 | #include <QFile> |
10 | #include <QXmlStreamReader> |
11 | #include <QRegularExpression> |
12 | #include <QQueue> |
13 | #include <QStack> |
14 | |
15 | #include <limits> |
16 | |
17 | const char PROFILER_FILE_VERSION[] = "1.02" ; |
18 | |
19 | static const char *RANGE_TYPE_STRINGS[] = { |
20 | "Painting" , |
21 | "Compiling" , |
22 | "Creating" , |
23 | "Binding" , |
24 | "HandlingSignal" , |
25 | "Javascript" |
26 | }; |
27 | |
28 | Q_STATIC_ASSERT(sizeof(RANGE_TYPE_STRINGS) == MaximumRangeType * sizeof(const char *)); |
29 | |
30 | static const char *MESSAGE_STRINGS[] = { |
31 | "Event" , |
32 | "RangeStart" , |
33 | "RangeData" , |
34 | "RangeLocation" , |
35 | "RangeEnd" , |
36 | "Complete" , |
37 | "PixmapCache" , |
38 | "SceneGraph" , |
39 | "MemoryAllocation" , |
40 | "DebugMessage" |
41 | }; |
42 | |
43 | Q_STATIC_ASSERT(sizeof(MESSAGE_STRINGS) == MaximumMessage * sizeof(const char *)); |
44 | |
45 | ///////////////////////////////////////////////////////////////// |
46 | class QmlProfilerDataPrivate |
47 | { |
48 | public: |
49 | QmlProfilerDataPrivate(QmlProfilerData *qq){ Q_UNUSED(qq); } |
50 | |
51 | // data storage |
52 | QVector<QQmlProfilerEventType> eventTypes; |
53 | QVector<QQmlProfilerEvent> events; |
54 | |
55 | qint64 traceStartTime; |
56 | qint64 traceEndTime; |
57 | |
58 | // internal state while collecting events |
59 | qint64 qmlMeasuredTime; |
60 | QmlProfilerData::State state; |
61 | }; |
62 | |
63 | ///////////////////////////////////////////////////////////////// |
64 | QmlProfilerData::QmlProfilerData(QObject *parent) : |
65 | QQmlProfilerEventReceiver(parent), d(new QmlProfilerDataPrivate(this)) |
66 | { |
67 | d->state = Empty; |
68 | clear(); |
69 | } |
70 | |
71 | QmlProfilerData::~QmlProfilerData() |
72 | { |
73 | clear(); |
74 | delete d; |
75 | } |
76 | |
77 | void QmlProfilerData::clear() |
78 | { |
79 | d->events.clear(); |
80 | |
81 | d->traceEndTime = std::numeric_limits<qint64>::min(); |
82 | d->traceStartTime = std::numeric_limits<qint64>::max(); |
83 | d->qmlMeasuredTime = 0; |
84 | |
85 | setState(Empty); |
86 | } |
87 | |
88 | QString QmlProfilerData::qmlRangeTypeAsString(RangeType type) |
89 | { |
90 | if (type * sizeof(char *) < sizeof(RANGE_TYPE_STRINGS)) |
91 | return QLatin1String(RANGE_TYPE_STRINGS[type]); |
92 | else |
93 | return QString::number(type); |
94 | } |
95 | |
96 | QString QmlProfilerData::qmlMessageAsString(Message type) |
97 | { |
98 | if (type * sizeof(char *) < sizeof(MESSAGE_STRINGS)) |
99 | return QLatin1String(MESSAGE_STRINGS[type]); |
100 | else |
101 | return QString::number(type); |
102 | } |
103 | |
104 | void QmlProfilerData::setTraceStartTime(qint64 time) |
105 | { |
106 | if (time < d->traceStartTime) |
107 | d->traceStartTime = time; |
108 | } |
109 | |
110 | void QmlProfilerData::setTraceEndTime(qint64 time) |
111 | { |
112 | if (time > d->traceEndTime) |
113 | d->traceEndTime = time; |
114 | } |
115 | |
116 | qint64 QmlProfilerData::traceStartTime() const |
117 | { |
118 | return d->traceStartTime; |
119 | } |
120 | |
121 | qint64 QmlProfilerData::traceEndTime() const |
122 | { |
123 | return d->traceEndTime; |
124 | } |
125 | |
126 | void QmlProfilerData::addEvent(const QQmlProfilerEvent &event) |
127 | { |
128 | setState(AcquiringData); |
129 | d->events.append(t: event); |
130 | } |
131 | |
132 | void QmlProfilerData::addEventType(const QQmlProfilerEventType &type) |
133 | { |
134 | QQmlProfilerEventType newType = type; |
135 | |
136 | QString details; |
137 | // generate details string |
138 | if (!type.data().isEmpty()) { |
139 | details = type.data().simplified(); |
140 | QRegularExpression rewrite(QStringLiteral("^\\(function \\$(\\w+)\\(\\) \\{ (return |)(.+) \\}\\)$" )); |
141 | QRegularExpressionMatch match = rewrite.match(subject: details); |
142 | if (match.hasMatch()) { |
143 | details = match.captured(nth: 1) +QLatin1String(": " ) + match.captured(nth: 3); |
144 | } |
145 | if (details.startsWith(s: QLatin1String("file://" ))) |
146 | details = details.mid(position: details.lastIndexOf(c: QLatin1Char('/')) + 1); |
147 | } |
148 | |
149 | newType.setData(details); |
150 | |
151 | QString displayName; |
152 | switch (type.message()) { |
153 | case Event: { |
154 | switch (type.detailType()) { |
155 | case Mouse: |
156 | case Key: |
157 | displayName = QString::fromLatin1(ba: "Input:%1" ).arg(a: type.detailType()); |
158 | break; |
159 | case AnimationFrame: |
160 | displayName = QString::fromLatin1(ba: "AnimationFrame" ); |
161 | break; |
162 | default: |
163 | displayName = QString::fromLatin1(ba: "Unknown" ); |
164 | } |
165 | break; |
166 | } |
167 | case RangeStart: |
168 | case RangeData: |
169 | case RangeLocation: |
170 | case RangeEnd: |
171 | case Complete: |
172 | Q_UNREACHABLE(); |
173 | break; |
174 | case PixmapCacheEvent: { |
175 | const QString filePath = QUrl(type.location().filename()).path(); |
176 | displayName = QStringView{filePath}.mid(pos: filePath.lastIndexOf(c: QLatin1Char('/')) + 1) |
177 | + QLatin1Char(':') + QString::number(type.detailType()); |
178 | break; |
179 | } |
180 | case SceneGraphFrame: |
181 | displayName = QString::fromLatin1(ba: "SceneGraph:%1" ).arg(a: type.detailType()); |
182 | break; |
183 | case MemoryAllocation: |
184 | displayName = QString::fromLatin1(ba: "MemoryAllocation:%1" ).arg(a: type.detailType()); |
185 | break; |
186 | case DebugMessage: |
187 | displayName = QString::fromLatin1(ba: "DebugMessage:%1" ).arg(a: type.detailType()); |
188 | break; |
189 | case MaximumMessage: { |
190 | const QQmlProfilerEventLocation eventLocation = type.location(); |
191 | // generate hash |
192 | if (eventLocation.filename().isEmpty()) { |
193 | displayName = QString::fromLatin1(ba: "Unknown" ); |
194 | } else { |
195 | const QString filePath = QUrl(eventLocation.filename()).path(); |
196 | displayName = QStringView{filePath}.mid( |
197 | pos: filePath.lastIndexOf(c: QLatin1Char('/')) + 1) + |
198 | QLatin1Char(':') + QString::number(eventLocation.line()); |
199 | } |
200 | break; |
201 | } |
202 | } |
203 | |
204 | newType.setDisplayName(displayName); |
205 | d->eventTypes.append(t: newType); |
206 | } |
207 | |
208 | void QmlProfilerData::computeQmlTime() |
209 | { |
210 | // compute levels |
211 | qint64 level0Start = -1; |
212 | int level = 0; |
213 | |
214 | for (const QQmlProfilerEvent &event : std::as_const(t&: d->events)) { |
215 | const QQmlProfilerEventType &type = d->eventTypes.at(i: event.typeIndex()); |
216 | if (type.message() != MaximumMessage) |
217 | continue; |
218 | |
219 | switch (type.rangeType()) { |
220 | case Compiling: |
221 | case Creating: |
222 | case Binding: |
223 | case HandlingSignal: |
224 | case Javascript: |
225 | switch (event.rangeStage()) { |
226 | case RangeStart: |
227 | if (level++ == 0) |
228 | level0Start = event.timestamp(); |
229 | break; |
230 | case RangeEnd: |
231 | if (--level == 0) |
232 | d->qmlMeasuredTime += event.timestamp() - level0Start; |
233 | break; |
234 | default: |
235 | break; |
236 | } |
237 | break; |
238 | default: |
239 | break; |
240 | } |
241 | } |
242 | } |
243 | |
244 | bool compareStartTimes(const QQmlProfilerEvent &t1, const QQmlProfilerEvent &t2) |
245 | { |
246 | return t1.timestamp() < t2.timestamp(); |
247 | } |
248 | |
249 | void QmlProfilerData::sortStartTimes() |
250 | { |
251 | if (d->events.size() < 2) |
252 | return; |
253 | |
254 | // assuming startTimes is partially sorted |
255 | // identify blocks of events and sort them with quicksort |
256 | QVector<QQmlProfilerEvent>::iterator itFrom = d->events.end() - 2; |
257 | QVector<QQmlProfilerEvent>::iterator itTo = d->events.end() - 1; |
258 | |
259 | while (itFrom != d->events.begin() && itTo != d->events.begin()) { |
260 | // find block to sort |
261 | while (itFrom != d->events.begin() && itTo->timestamp() > itFrom->timestamp()) { |
262 | --itTo; |
263 | itFrom = itTo - 1; |
264 | } |
265 | |
266 | // if we're at the end of the list |
267 | if (itFrom == d->events.begin()) |
268 | break; |
269 | |
270 | // find block length |
271 | while (itFrom != d->events.begin() && itTo->timestamp() <= itFrom->timestamp()) |
272 | --itFrom; |
273 | |
274 | if (itTo->timestamp() <= itFrom->timestamp()) |
275 | std::sort(first: itFrom, last: itTo + 1, comp: compareStartTimes); |
276 | else |
277 | std::sort(first: itFrom + 1, last: itTo + 1, comp: compareStartTimes); |
278 | |
279 | // move to next block |
280 | itTo = itFrom; |
281 | itFrom = itTo - 1; |
282 | } |
283 | } |
284 | |
285 | void QmlProfilerData::complete() |
286 | { |
287 | setState(ProcessingData); |
288 | sortStartTimes(); |
289 | computeQmlTime(); |
290 | setState(Done); |
291 | emit dataReady(); |
292 | } |
293 | |
294 | bool QmlProfilerData::isEmpty() const |
295 | { |
296 | return d->events.isEmpty(); |
297 | } |
298 | |
299 | struct StreamWriter { |
300 | QString error; |
301 | |
302 | StreamWriter(const QString &filename) |
303 | { |
304 | if (!filename.isEmpty()) { |
305 | file.setFileName(filename); |
306 | if (!file.open(flags: QIODevice::WriteOnly)) { |
307 | error = QmlProfilerData::tr(s: "Could not open %1 for writing" ).arg(a: filename); |
308 | return; |
309 | } |
310 | } else { |
311 | if (!file.open(stdout, ioFlags: QIODevice::WriteOnly)) { |
312 | error = QmlProfilerData::tr(s: "Could not open stdout for writing" ); |
313 | return; |
314 | } |
315 | } |
316 | |
317 | stream.setDevice(&file); |
318 | stream.setAutoFormatting(true); |
319 | stream.writeStartDocument(); |
320 | writeStartElement(name: "trace" ); |
321 | } |
322 | |
323 | ~StreamWriter() { |
324 | writeEndElement(); |
325 | stream.writeEndDocument(); |
326 | file.close(); |
327 | } |
328 | |
329 | template<typename Number> |
330 | void writeAttribute(const char *name, Number number) |
331 | { |
332 | stream.writeAttribute(QLatin1String(name), QString::number(number)); |
333 | } |
334 | |
335 | void writeAttribute(const char *name, const char *value) |
336 | { |
337 | stream.writeAttribute(qualifiedName: QLatin1String(name), value: QLatin1String(value)); |
338 | } |
339 | |
340 | void writeAttribute(const char *name, const QQmlProfilerEvent &event, int i, bool printZero = true) |
341 | { |
342 | const qint64 number = event.number<qint64>(i); |
343 | if (printZero || number != 0) |
344 | writeAttribute(name, number); |
345 | } |
346 | |
347 | template<typename Number> |
348 | void writeTextElement(const char *name, Number number) |
349 | { |
350 | writeTextElement(name, QString::number(number)); |
351 | } |
352 | |
353 | void writeTextElement(const char *name, const char *value) |
354 | { |
355 | stream.writeTextElement(qualifiedName: QLatin1String(name), text: QLatin1String(value)); |
356 | } |
357 | |
358 | void writeTextElement(const char *name, const QString &value) |
359 | { |
360 | stream.writeTextElement(qualifiedName: QLatin1String(name), text: value); |
361 | } |
362 | |
363 | void writeStartElement(const char *name) |
364 | { |
365 | stream.writeStartElement(qualifiedName: QLatin1String(name)); |
366 | } |
367 | |
368 | void writeEndElement() |
369 | { |
370 | stream.writeEndElement(); |
371 | } |
372 | |
373 | private: |
374 | QFile file; |
375 | QXmlStreamWriter stream; |
376 | }; |
377 | |
378 | bool QmlProfilerData::save(const QString &filename) |
379 | { |
380 | if (isEmpty()) { |
381 | emit error(tr(s: "No data to save" )); |
382 | return false; |
383 | } |
384 | |
385 | StreamWriter stream(filename); |
386 | if (!stream.error.isEmpty()) { |
387 | emit error(stream.error); |
388 | return false; |
389 | } |
390 | |
391 | stream.writeAttribute(name: "version" , value: PROFILER_FILE_VERSION); |
392 | stream.writeAttribute(name: "traceStart" , number: traceStartTime()); |
393 | stream.writeAttribute(name: "traceEnd" , number: traceEndTime()); |
394 | |
395 | stream.writeStartElement(name: "eventData" ); |
396 | stream.writeAttribute(name: "totalTime" , number: d->qmlMeasuredTime); |
397 | |
398 | for (int typeIndex = 0, end = d->eventTypes.size(); typeIndex < end; ++typeIndex) { |
399 | const QQmlProfilerEventType &eventData = d->eventTypes.at(i: typeIndex); |
400 | stream.writeStartElement(name: "event" ); |
401 | stream.writeAttribute(name: "index" , number: typeIndex); |
402 | if (!eventData.displayName().isEmpty()) |
403 | stream.writeTextElement(name: "displayname" , value: eventData.displayName()); |
404 | |
405 | stream.writeTextElement(name: "type" , value: eventData.rangeType() == MaximumRangeType |
406 | ? qmlMessageAsString(type: eventData.message()) |
407 | : qmlRangeTypeAsString(type: eventData.rangeType())); |
408 | |
409 | const QQmlProfilerEventLocation location = eventData.location(); |
410 | if (!location.filename().isEmpty()) |
411 | stream.writeTextElement(name: "filename" , value: location.filename()); |
412 | if (location.line() >= 0) |
413 | stream.writeTextElement(name: "line" , number: location.line()); |
414 | if (location.column() >= 0) |
415 | stream.writeTextElement(name: "column" , number: location.column()); |
416 | if (!eventData.data().isEmpty()) |
417 | stream.writeTextElement(name: "details" , value: eventData.data()); |
418 | if (eventData.rangeType() == Binding) |
419 | stream.writeTextElement(name: "bindingType" , number: eventData.detailType()); |
420 | else if (eventData.message() == Event) { |
421 | switch (eventData.detailType()) { |
422 | case AnimationFrame: |
423 | stream.writeTextElement(name: "animationFrame" , number: eventData.detailType()); |
424 | break; |
425 | case Key: |
426 | stream.writeTextElement(name: "keyEvent" , number: eventData.detailType()); |
427 | break; |
428 | case Mouse: |
429 | stream.writeTextElement(name: "mouseEvent" , number: eventData.detailType()); |
430 | break; |
431 | } |
432 | } else if (eventData.message() == PixmapCacheEvent) |
433 | stream.writeTextElement(name: "cacheEventType" , number: eventData.detailType()); |
434 | else if (eventData.message() == SceneGraphFrame) |
435 | stream.writeTextElement(name: "sgEventType" , number: eventData.detailType()); |
436 | else if (eventData.message() == MemoryAllocation) |
437 | stream.writeTextElement(name: "memoryEventType" , number: eventData.detailType()); |
438 | stream.writeEndElement(); |
439 | } |
440 | stream.writeEndElement(); // eventData |
441 | |
442 | stream.writeStartElement(name: "profilerDataModel" ); |
443 | |
444 | auto sendEvent = [&](const QQmlProfilerEvent &event, qint64 duration = 0) { |
445 | const QQmlProfilerEventType &type = d->eventTypes.at(i: event.typeIndex()); |
446 | stream.writeStartElement(name: "range" ); |
447 | stream.writeAttribute(name: "startTime" , number: event.timestamp()); |
448 | if (duration != 0) |
449 | stream.writeAttribute(name: "duration" , number: duration); |
450 | stream.writeAttribute(name: "eventIndex" , number: event.typeIndex()); |
451 | if (type.message() == Event) { |
452 | if (type.detailType() == AnimationFrame) { |
453 | // special: animation frame |
454 | stream.writeAttribute(name: "framerate" , event, i: 0); |
455 | stream.writeAttribute(name: "animationcount" , event, i: 1); |
456 | stream.writeAttribute(name: "thread" , event, i: 2); |
457 | } else if (type.detailType() == Key || type.detailType() == Mouse) { |
458 | // numerical value here, to keep the format a bit more compact |
459 | stream.writeAttribute(name: "type" , event, i: 0); |
460 | stream.writeAttribute(name: "data1" , event, i: 1); |
461 | stream.writeAttribute(name: "data2" , event, i: 2); |
462 | } |
463 | } else if (type.message() == PixmapCacheEvent) { |
464 | // special: pixmap cache event |
465 | if (type.detailType() == PixmapSizeKnown) { |
466 | stream.writeAttribute(name: "width" , event, i: 0); |
467 | stream.writeAttribute(name: "height" , event, i: 1); |
468 | } else if (type.detailType() == PixmapReferenceCountChanged |
469 | || type.detailType() == PixmapCacheCountChanged) { |
470 | stream.writeAttribute(name: "refCount" , event, i: 1); |
471 | } |
472 | } else if (type.message() == SceneGraphFrame) { |
473 | stream.writeAttribute(name: "timing1" , event, i: 0, printZero: false); |
474 | stream.writeAttribute(name: "timing2" , event, i: 1, printZero: false); |
475 | stream.writeAttribute(name: "timing3" , event, i: 2, printZero: false); |
476 | stream.writeAttribute(name: "timing4" , event, i: 3, printZero: false); |
477 | stream.writeAttribute(name: "timing5" , event, i: 4, printZero: false); |
478 | } else if (type.message() == MemoryAllocation) { |
479 | stream.writeAttribute(name: "amount" , event, i: 0); |
480 | } |
481 | stream.writeEndElement(); |
482 | }; |
483 | |
484 | QQueue<QQmlProfilerEvent> pointEvents; |
485 | QQueue<QQmlProfilerEvent> rangeStarts[MaximumRangeType]; |
486 | QStack<qint64> rangeEnds[MaximumRangeType]; |
487 | int level = 0; |
488 | |
489 | auto sendPending = [&]() { |
490 | forever { |
491 | int minimum = MaximumRangeType; |
492 | qint64 minimumTime = std::numeric_limits<qint64>::max(); |
493 | for (int i = 0; i < MaximumRangeType; ++i) { |
494 | const QQueue<QQmlProfilerEvent> &starts = rangeStarts[i]; |
495 | if (starts.isEmpty()) |
496 | continue; |
497 | if (starts.head().timestamp() < minimumTime) { |
498 | minimumTime = starts.head().timestamp(); |
499 | minimum = i; |
500 | } |
501 | } |
502 | if (minimum == MaximumRangeType) |
503 | break; |
504 | |
505 | while (!pointEvents.isEmpty() && pointEvents.front().timestamp() < minimumTime) |
506 | sendEvent(pointEvents.dequeue()); |
507 | |
508 | sendEvent(rangeStarts[minimum].dequeue(), |
509 | rangeEnds[minimum].pop() - minimumTime); |
510 | } |
511 | }; |
512 | |
513 | for (const QQmlProfilerEvent &event : std::as_const(t&: d->events)) { |
514 | const QQmlProfilerEventType &type = d->eventTypes.at(i: event.typeIndex()); |
515 | |
516 | if (type.rangeType() != MaximumRangeType) { |
517 | QQueue<QQmlProfilerEvent> &starts = rangeStarts[type.rangeType()]; |
518 | switch (event.rangeStage()) { |
519 | case RangeStart: { |
520 | ++level; |
521 | starts.enqueue(t: event); |
522 | break; |
523 | } |
524 | case RangeEnd: { |
525 | QStack<qint64> &ends = rangeEnds[type.rangeType()]; |
526 | if (starts.size() > ends.size()) { |
527 | ends.push(t: event.timestamp()); |
528 | if (--level == 0) |
529 | sendPending(); |
530 | } |
531 | break; |
532 | } |
533 | default: |
534 | break; |
535 | } |
536 | } else { |
537 | if (level == 0) |
538 | sendEvent(event); |
539 | else |
540 | pointEvents.enqueue(t: event); |
541 | } |
542 | } |
543 | |
544 | for (int i = 0; i < MaximumRangeType; ++i) { |
545 | while (rangeEnds[i].size() < rangeStarts[i].size()) { |
546 | rangeEnds[i].push(t: d->traceEndTime); |
547 | --level; |
548 | } |
549 | } |
550 | |
551 | sendPending(); |
552 | |
553 | stream.writeEndElement(); // profilerDataModel |
554 | |
555 | return true; |
556 | } |
557 | |
558 | void QmlProfilerData::setState(QmlProfilerData::State state) |
559 | { |
560 | // It's not an error, we are continuously calling "AcquiringData" for example |
561 | if (d->state == state) |
562 | return; |
563 | |
564 | switch (state) { |
565 | case Empty: |
566 | // if it's not empty, complain but go on |
567 | if (!isEmpty()) |
568 | emit error("Invalid qmlprofiler state change (Empty)" ); |
569 | break; |
570 | case AcquiringData: |
571 | // we're not supposed to receive new data while processing older data |
572 | if (d->state == ProcessingData) |
573 | emit error("Invalid qmlprofiler state change (AcquiringData)" ); |
574 | break; |
575 | case ProcessingData: |
576 | if (d->state != AcquiringData) |
577 | emit error("Invalid qmlprofiler state change (ProcessingData)" ); |
578 | break; |
579 | case Done: |
580 | if (d->state != ProcessingData && d->state != Empty) |
581 | emit error("Invalid qmlprofiler state change (Done)" ); |
582 | break; |
583 | default: |
584 | emit error("Trying to set unknown state in events list" ); |
585 | break; |
586 | } |
587 | |
588 | d->state = state; |
589 | emit stateChanged(); |
590 | |
591 | // special: if we were done with an empty list, clean internal data and go back to empty |
592 | if (d->state == Done && isEmpty()) { |
593 | clear(); |
594 | } |
595 | return; |
596 | } |
597 | |
598 | int QmlProfilerData::numLoadedEventTypes() const |
599 | { |
600 | return d->eventTypes.size(); |
601 | } |
602 | |
603 | #include "moc_qmlprofilerdata.cpp" |
604 | |