tools/qmlprofiler/qmlprofilerdata.cpp

   1 /****************************************************************************
   2 **
   3 ** Copyright (C) 2012 Nokia Corporation and/or its subsidiary(-ies).
   4 ** Contact: http://www.qt-project.org/
   5 **
   6 ** This file is part of the QtQml module of the Qt Toolkit.
   7 **
   8 ** $QT_BEGIN_LICENSE:LGPL$
   9 ** GNU Lesser General Public License Usage
  10 ** This file may be used under the terms of the GNU Lesser General Public
  11 ** License version 2.1 as published by the Free Software Foundation and
  12 ** appearing in the file LICENSE.LGPL included in the packaging of this
  13 ** file. Please review the following information to ensure the GNU Lesser
  14 ** General Public License version 2.1 requirements will be met:
  15 ** http://www.gnu.org/licenses/old-licenses/lgpl-2.1.html.
  16 **
  17 ** In addition, as a special exception, Nokia gives you certain additional
  18 ** rights. These rights are described in the Nokia Qt LGPL Exception
  19 ** version 1.1, included in the file LGPL_EXCEPTION.txt in this package.
  20 **
  21 ** GNU General Public License Usage
  22 ** Alternatively, this file may be used under the terms of the GNU General
  23 ** Public License version 3.0 as published by the Free Software Foundation
  24 ** and appearing in the file LICENSE.GPL included in the packaging of this
  25 ** file. Please review the following information to ensure the GNU General
  26 ** Public License version 3.0 requirements will be met:
  27 ** http://www.gnu.org/copyleft/gpl.html.
  28 **
  29 ** Other Usage
  30 ** Alternatively, this file may be used in accordance with the terms and
  31 ** conditions contained in a signed written agreement between you and Nokia.
  32 **
  33 **
  34 **
  35 **
  36 **
  37 **
  38 ** $QT_END_LICENSE$
  39 **
  40 ****************************************************************************/
  41
  42 #include "qmlprofilerdata.h"
  43
  44 #include <QStringList>
  45 #include <QUrl>
  46 #include <QHash>
  47 #include <QFile>
  48 #include <QXmlStreamReader>
  49
  50 namespace Constants {
  51     const char TYPE_PAINTING_STR[] = "Painting";
  52     const char TYPE_COMPILING_STR[] = "Compiling";
  53     const char TYPE_CREATING_STR[] = "Creating";
  54     const char TYPE_BINDING_STR[] = "Binding";
  55     const char TYPE_HANDLINGSIGNAL_STR[] = "HandlingSignal";
  56     const char PROFILER_FILE_VERSION[] = "1.02";
  57 }
  58
  59 struct QmlRangeEventData {
  60     QmlRangeEventData() {} // never called
  61     QmlRangeEventData(const QString &_displayName,
  62                  const QString &_eventHashStr,
  63                  const QmlEventLocation &_location,
  64                  const QString &_details,
  65                  const QQmlProfilerService::RangeType &_eventType)
  66         : displayName(_displayName),eventHashStr(_eventHashStr),location(_location),
  67           details(_details),eventType(_eventType) {}
  68     QString displayName;
  69     QString eventHashStr;
  70     QmlEventLocation location;
  71     QString details;
  72     QQmlProfilerService::RangeType eventType;
  73 };
  74
  75 struct QmlRangeEventStartInstance {
  76     QmlRangeEventStartInstance() {} // never called
  77     QmlRangeEventStartInstance(qint64 _startTime, qint64 _duration, int _frameRate,
  78                   int _animationCount, QmlRangeEventData *_data)
  79         : startTime(_startTime), duration(_duration), frameRate(_frameRate),
  80           animationCount(_animationCount), data(_data)
  81         { }
  82     qint64 startTime;
  83     qint64 duration;
  84     int frameRate;
  85     int animationCount;
  86     QmlRangeEventData *data;
  87 };
  88
  89 QT_BEGIN_NAMESPACE
  90 Q_DECLARE_TYPEINFO(QmlRangeEventData, Q_MOVABLE_TYPE);
  91 Q_DECLARE_TYPEINFO(QmlRangeEventStartInstance, Q_MOVABLE_TYPE);
  92 QT_END_NAMESPACE
  93
  94 struct QV8EventInfo {
  95     QString displayName;
  96     QString eventHashStr;
  97     QString functionName;
  98     QString fileName;
  99     int line;
 100     qint64 totalTime;
 101     qint64 selfTime;
 102
 103     QHash<QString, qint64> v8children;
 104 };
 105
 106 /////////////////////////////////////////////////////////////////
 107 class QmlProfilerDataPrivate
 108 {
 109 public:
 110     QmlProfilerDataPrivate(QmlProfilerData *qq){ Q_UNUSED(qq); }
 111
 112     // data storage
 113     QHash<QString, QmlRangeEventData *> eventDescriptions;
 114     QVector<QmlRangeEventStartInstance> startInstanceList;
 115     QHash<QString, QV8EventInfo *> v8EventHash;
 116
 117     qint64 traceStartTime;
 118     qint64 traceEndTime;
 119
 120     // internal state while collecting events
 121     QmlRangeEventStartInstance *lastFrameEvent;
 122     qint64 qmlMeasuredTime;
 123     qint64 v8MeasuredTime;
 124     QHash<int, QV8EventInfo *> v8parents;
 125     void clearV8RootEvent();
 126     QV8EventInfo v8RootEvent;
 127
 128     QmlProfilerData::State state;
 129 };
 130
 131 /////////////////////////////////////////////////////////////////
 132 QmlProfilerData::QmlProfilerData(QObject *parent) :
 133     QObject(parent),d(new QmlProfilerDataPrivate(this))
 134 {
 135     d->state = Empty;
 136     clear();
 137 }
 138
 139 QmlProfilerData::~QmlProfilerData()
 140 {
 141     clear();
 142     delete d;
 143 }
 144
 145 void QmlProfilerData::clear()
 146 {
 147     qDeleteAll(d->eventDescriptions.values());
 148     d->eventDescriptions.clear();
 149     d->startInstanceList.clear();
 150
 151     qDeleteAll(d->v8EventHash.values());
 152     d->v8EventHash.clear();
 153     d->v8parents.clear();
 154     d->clearV8RootEvent();
 155     d->v8MeasuredTime = 0;
 156
 157     d->traceEndTime = 0;
 158     d->traceStartTime = -1;
 159     d->qmlMeasuredTime = 0;
 160
 161     d->lastFrameEvent = 0;
 162
 163     setState(Empty);
 164 }
 165
 166 QString QmlProfilerData::getHashStringForQmlEvent(const QmlEventLocation &location, int eventType)
 167 {
 168     return QString(QStringLiteral("%1:%2:%3:%4")).arg(
 169                 location.filename,
 170                 QString::number(location.line),
 171                 QString::number(location.column),
 172                 QString::number(eventType));
 173 }
 174
 175 QString QmlProfilerData::getHashStringForV8Event(const QString &displayName, const QString &function)
 176 {
 177     return QString(QStringLiteral("%1:%2")).arg(displayName, function);
 178 }
 179
 180 QString QmlProfilerData::qmlRangeTypeAsString(QQmlProfilerService::RangeType typeEnum)
 181 {
 182     switch (typeEnum) {
 183     case QQmlProfilerService::Painting:
 184         return QLatin1String(Constants::TYPE_PAINTING_STR);
 185         break;
 186     case QQmlProfilerService::Compiling:
 187         return QLatin1String(Constants::TYPE_COMPILING_STR);
 188         break;
 189     case QQmlProfilerService::Creating:
 190         return QLatin1String(Constants::TYPE_CREATING_STR);
 191         break;
 192     case QQmlProfilerService::Binding:
 193         return QLatin1String(Constants::TYPE_BINDING_STR);
 194         break;
 195     case QQmlProfilerService::HandlingSignal:
 196         return QLatin1String(Constants::TYPE_HANDLINGSIGNAL_STR);
 197         break;
 198     default:
 199         return QString::number((int)typeEnum);
 200     }
 201 }
 202
 203 void QmlProfilerData::setTraceStartTime(qint64 time)
 204 {
 205     d->traceStartTime = time;
 206 }
 207
 208 void QmlProfilerData::setTraceEndTime(qint64 time)
 209 {
 210     d->traceEndTime = time;
 211 }
 212
 213 qint64 QmlProfilerData::traceStartTime() const
 214 {
 215     return d->traceStartTime;
 216 }
 217
 218 qint64 QmlProfilerData::traceEndTime() const
 219 {
 220     return d->traceEndTime;
 221 }
 222
 223 void QmlProfilerData::addQmlEvent(QQmlProfilerService::RangeType type,
 224                                   qint64 startTime,
 225                                   qint64 duration,
 226                                   const QStringList &data,
 227                                   const QmlEventLocation &location)
 228 {
 229     setState(AcquiringData);
 230
 231     QString details;
 232     // generate details string
 233     if (data.isEmpty())
 234         details = tr("Source code not available");
 235     else {
 236         details = data.join(QStringLiteral(" ")).replace(
 237                     QLatin1Char('\n'),QStringLiteral(" ")).simplified();
 238         QRegExp rewrite(QStringLiteral("\\(function \\$(\\w+)\\(\\) \\{ (return |)(.+) \\}\\)"));
 239         bool match = rewrite.exactMatch(details);
 240         if (match) {
 241             details = rewrite.cap(1) +QLatin1String(": ") + rewrite.cap(3);
 242         }
 243         if (details.startsWith(QLatin1String("file://")))
 244             details = details.mid(details.lastIndexOf(QLatin1Char('/')) + 1);
 245     }
 246
 247     QmlEventLocation eventLocation = location;
 248     QString displayName, eventHashStr;
 249     // generate hash
 250     if (eventLocation.filename.isEmpty()) {
 251         displayName = tr("<bytecode>");
 252         eventHashStr = getHashStringForQmlEvent(eventLocation, type);
 253     } else {
 254         const QString filePath = QUrl(eventLocation.filename).path();
 255         displayName = filePath.mid(
 256                     filePath.lastIndexOf(QLatin1Char('/')) + 1) +
 257                     QLatin1Char(':') + QString::number(eventLocation.line);
 258         eventHashStr = getHashStringForQmlEvent(eventLocation, type);
 259     }
 260
 261     QmlRangeEventData *newEvent;
 262     if (d->eventDescriptions.contains(eventHashStr)) {
 263         newEvent = d->eventDescriptions[eventHashStr];
 264     } else {
 265         newEvent = new QmlRangeEventData(displayName, eventHashStr, location, details, type);
 266         d->eventDescriptions.insert(eventHashStr, newEvent);
 267     }
 268
 269     QmlRangeEventStartInstance rangeEventStartInstance(startTime, duration, 1e9/duration, -1, newEvent);
 270
 271     d->startInstanceList.append(rangeEventStartInstance);
 272 }
 273
 274 void QmlProfilerData::addFrameEvent(qint64 time, int framerate, int animationcount)
 275 {
 276     setState(AcquiringData);
 277
 278     QString details = tr("Animation Timer Update");
 279     QString displayName = tr("<Animation Update>");
 280     QString eventHashStr = displayName;
 281
 282     QmlRangeEventData *newEvent;
 283     if (d->eventDescriptions.contains(eventHashStr)) {
 284         newEvent = d->eventDescriptions[eventHashStr];
 285     } else {
 286         newEvent = new QmlRangeEventData(displayName, eventHashStr, QmlEventLocation(), details, QQmlProfilerService::Painting);
 287         d->eventDescriptions.insert(eventHashStr, newEvent);
 288     }
 289
 290     qint64 duration = 1e9/framerate;
 291     // avoid overlap
 292     if (d->lastFrameEvent &&
 293             d->lastFrameEvent->startTime + d->lastFrameEvent->duration >= time) {
 294         d->lastFrameEvent->duration = time - 1 - d->lastFrameEvent->startTime;
 295     }
 296
 297     QmlRangeEventStartInstance rangeEventStartInstance(time, duration, framerate, animationcount, newEvent);
 298
 299     d->startInstanceList.append(rangeEventStartInstance);
 300
 301     d->lastFrameEvent = &d->startInstanceList.last();
 302 }
 303
 304 QString QmlProfilerData::rootEventName()
 305 {
 306     return tr("<program>");
 307 }
 308
 309 QString QmlProfilerData::rootEventDescription()
 310 {
 311     return tr("Main Program");
 312 }
 313
 314 void QmlProfilerDataPrivate::clearV8RootEvent()
 315 {
 316     v8RootEvent.displayName = QmlProfilerData::rootEventName();
 317     v8RootEvent.eventHashStr = QmlProfilerData::rootEventName();
 318     v8RootEvent.functionName = QmlProfilerData::rootEventDescription();
 319     v8RootEvent.line = -1;
 320     v8RootEvent.totalTime = 0;
 321     v8RootEvent.selfTime = 0;
 322     v8RootEvent.v8children.clear();
 323 }
 324
 325 void QmlProfilerData::addV8Event(int depth, const QString &function, const QString &filename,
 326                                  int lineNumber, double totalTime, double selfTime)
 327 {
 328     QString displayName = filename.mid(filename.lastIndexOf(QLatin1Char('/')) + 1) +
 329             QLatin1Char(':') + QString::number(lineNumber);
 330     QString hashStr = getHashStringForV8Event(displayName, function);
 331
 332     setState(AcquiringData);
 333
 334     // time is given in milliseconds, but internally we store it in microseconds
 335     totalTime *= 1e6;
 336     selfTime *= 1e6;
 337
 338     // accumulate information
 339     QV8EventInfo *eventData = d->v8EventHash[hashStr];
 340     if (!eventData) {
 341         eventData = new QV8EventInfo;
 342         eventData->displayName = displayName;
 343         eventData->eventHashStr = hashStr;
 344         eventData->fileName = filename;
 345         eventData->functionName = function;
 346         eventData->line = lineNumber;
 347         eventData->totalTime = totalTime;
 348         eventData->selfTime = selfTime;
 349         d->v8EventHash[hashStr] = eventData;
 350     } else {
 351         eventData->totalTime += totalTime;
 352         eventData->selfTime += selfTime;
 353     }
 354     d->v8parents[depth] = eventData;
 355
 356     QV8EventInfo *parentEvent = 0;
 357     if (depth == 0) {
 358         parentEvent = &d->v8RootEvent;
 359         d->v8MeasuredTime += totalTime;
 360     }
 361     if (depth > 0 && d->v8parents.contains(depth-1)) {
 362         parentEvent = d->v8parents.value(depth-1);
 363     }
 364
 365     if (parentEvent != 0) {
 366         if (!parentEvent->v8children.contains(eventData->eventHashStr)) {
 367             parentEvent->v8children[eventData->eventHashStr] = totalTime;
 368         } else {
 369             parentEvent->v8children[eventData->eventHashStr] += totalTime;
 370         }
 371     }
 372 }
 373
 374 void QmlProfilerData::computeQmlTime()
 375 {
 376     // compute levels
 377     QHash<int, qint64> endtimesPerLevel;
 378     int minimumLevel = 1;
 379     int level = minimumLevel;
 380
 381     for (int i = 0; i < d->startInstanceList.count(); i++) {
 382         qint64 st = d->startInstanceList[i].startTime;
 383         int type = d->startInstanceList[i].data->eventType;
 384
 385         if (type == QQmlProfilerService::Painting) {
 386             continue;
 387         }
 388
 389         // general level
 390         if (endtimesPerLevel[level] > st) {
 391             level++;
 392         } else {
 393             while (level > minimumLevel && endtimesPerLevel[level-1] <= st)
 394                 level--;
 395         }
 396         endtimesPerLevel[level] = st + d->startInstanceList[i].duration;
 397
 398         if (level == minimumLevel) {
 399             d->qmlMeasuredTime += d->startInstanceList[i].duration;
 400         }
 401     }
 402 }
 403
 404 bool compareStartTimes(const QmlRangeEventStartInstance &t1, const QmlRangeEventStartInstance &t2)
 405 {
 406     return t1.startTime < t2.startTime;
 407 }
 408
 409 void QmlProfilerData::sortStartTimes()
 410 {
 411     if (d->startInstanceList.count() < 2)
 412         return;
 413
 414     // assuming startTimes is partially sorted
 415     // identify blocks of events and sort them with quicksort
 416     QVector<QmlRangeEventStartInstance>::iterator itFrom = d->startInstanceList.end() - 2;
 417     QVector<QmlRangeEventStartInstance>::iterator itTo = d->startInstanceList.end() - 1;
 418
 419     while (itFrom != d->startInstanceList.begin() && itTo != d->startInstanceList.begin()) {
 420         // find block to sort
 421         while ( itFrom != d->startInstanceList.begin()
 422                 && itTo->startTime > itFrom->startTime ) {
 423             itTo--;
 424             itFrom = itTo - 1;
 425         }
 426
 427         // if we're at the end of the list
 428         if (itFrom == d->startInstanceList.begin())
 429             break;
 430
 431         // find block length
 432         while ( itFrom != d->startInstanceList.begin()
 433                 && itTo->startTime <= itFrom->startTime )
 434             itFrom--;
 435
 436         if (itTo->startTime <= itFrom->startTime)
 437             qSort(itFrom, itTo + 1, compareStartTimes);
 438         else
 439             qSort(itFrom + 1, itTo + 1, compareStartTimes);
 440
 441         // move to next block
 442         itTo = itFrom;
 443         itFrom = itTo - 1;
 444     }
 445 }
 446
 447 void QmlProfilerData::complete()
 448 {
 449     setState(ProcessingData);
 450     sortStartTimes();
 451     computeQmlTime();
 452     setState(Done);
 453     emit dataReady();
 454 }
 455
 456 bool QmlProfilerData::isEmpty() const
 457 {
 458     return d->startInstanceList.isEmpty() && d->v8EventHash.isEmpty();
 459 }
 460
 461 bool QmlProfilerData::save(const QString &filename)
 462 {
 463     if (isEmpty()) {
 464         emit error(tr("No data to save"));
 465         return false;
 466     }
 467
 468     QFile file(filename);
 469     if (!file.open(QIODevice::WriteOnly)) {
 470         emit error(tr("Could not open %1 for writing").arg(filename));
 471         return false;
 472     }
 473
 474     QXmlStreamWriter stream(&file);
 475     stream.setAutoFormatting(true);
 476     stream.writeStartDocument();
 477
 478     stream.writeStartElement(QStringLiteral("trace"));
 479     stream.writeAttribute(QStringLiteral("version"), QLatin1String(Constants::PROFILER_FILE_VERSION));
 480
 481     stream.writeAttribute(QStringLiteral("traceStart"), QString::number(traceStartTime()));
 482     stream.writeAttribute(QStringLiteral("traceEnd"), QString::number(traceEndTime()));
 483
 484     stream.writeStartElement(QStringLiteral("eventData"));
 485     stream.writeAttribute(QStringLiteral("totalTime"), QString::number(d->qmlMeasuredTime));
 486
 487     foreach (const QmlRangeEventData *eventData, d->eventDescriptions.values()) {
 488         stream.writeStartElement(QStringLiteral("event"));
 489         stream.writeAttribute(QStringLiteral("index"), QString::number(d->eventDescriptions.keys().indexOf(eventData->eventHashStr)));
 490         stream.writeTextElement(QStringLiteral("displayname"), eventData->displayName);
 491         stream.writeTextElement(QStringLiteral("type"), qmlRangeTypeAsString(eventData->eventType));
 492         if (!eventData->location.filename.isEmpty()) {
 493             stream.writeTextElement(QStringLiteral("filename"), eventData->location.filename);
 494             stream.writeTextElement(QStringLiteral("line"), QString::number(eventData->location.line));
 495             stream.writeTextElement(QStringLiteral("column"), QString::number(eventData->location.column));
 496         }
 497         stream.writeTextElement(QStringLiteral("details"), eventData->details);
 498         stream.writeEndElement();
 499     }
 500     stream.writeEndElement(); // eventData
 501
 502     stream.writeStartElement(QStringLiteral("profilerDataModel"));
 503     foreach (const QmlRangeEventStartInstance &rangedEvent, d->startInstanceList) {
 504         stream.writeStartElement(QStringLiteral("range"));
 505         stream.writeAttribute(QStringLiteral("startTime"), QString::number(rangedEvent.startTime));
 506         stream.writeAttribute(QStringLiteral("duration"), QString::number(rangedEvent.duration));
 507         stream.writeAttribute(QStringLiteral("eventIndex"), QString::number(d->eventDescriptions.keys().indexOf(rangedEvent.data->eventHashStr)));
 508         if (rangedEvent.data->eventType == QQmlProfilerService::Painting && rangedEvent.animationCount >= 0) {
 509             // animation frame
 510             stream.writeAttribute(QStringLiteral("framerate"), QString::number(rangedEvent.frameRate));
 511             stream.writeAttribute(QStringLiteral("animationcount"), QString::number(rangedEvent.animationCount));
 512         }
 513         stream.writeEndElement();
 514     }
 515     stream.writeEndElement(); // profilerDataModel
 516
 517     stream.writeStartElement(QStringLiteral("v8profile")); // v8 profiler output
 518     stream.writeAttribute(QStringLiteral("totalTime"), QString::number(d->v8MeasuredTime));
 519     foreach (QV8EventInfo *v8event, d->v8EventHash.values()) {
 520         stream.writeStartElement(QStringLiteral("event"));
 521         stream.writeAttribute(QStringLiteral("index"), QString::number(d->v8EventHash.keys().indexOf(v8event->eventHashStr)));
 522         stream.writeTextElement(QStringLiteral("displayname"), v8event->displayName);
 523         stream.writeTextElement(QStringLiteral("functionname"), v8event->functionName);
 524         if (!v8event->fileName.isEmpty()) {
 525             stream.writeTextElement(QStringLiteral("filename"), v8event->fileName);
 526             stream.writeTextElement(QStringLiteral("line"), QString::number(v8event->line));
 527         }
 528         stream.writeTextElement(QStringLiteral("totalTime"), QString::number(v8event->totalTime));
 529         stream.writeTextElement(QStringLiteral("selfTime"), QString::number(v8event->selfTime));
 530         if (!v8event->v8children.isEmpty()) {
 531             stream.writeStartElement(QStringLiteral("childrenEvents"));
 532             QStringList childrenIndexes;
 533             QStringList childrenTimes;
 534             foreach (const QString &childHash, v8event->v8children.keys()) {
 535                 childrenIndexes << QString::number(v8EventIndex(childHash));
 536                 childrenTimes << QString::number(v8event->v8children[childHash]);
 537             }
 538
 539             stream.writeAttribute(QStringLiteral("list"), childrenIndexes.join(QString(", ")));
 540             stream.writeAttribute(QStringLiteral("childrenTimes"), childrenTimes.join(QString(", ")));
 541             stream.writeEndElement();
 542         }
 543         stream.writeEndElement();
 544     }
 545     stream.writeEndElement(); // v8 profiler output
 546
 547     stream.writeEndElement(); // trace
 548     stream.writeEndDocument();
 549
 550     file.close();
 551     return true;
 552 }
 553
 554 int QmlProfilerData::v8EventIndex(const QString &hashStr)
 555 {
 556     if (!d->v8EventHash.contains(hashStr)) {
 557         emit error("Trying to index nonexisting v8 event");
 558         return -1;
 559     }
 560     return d->v8EventHash.keys().indexOf( hashStr );
 561 }
 562
 563 void QmlProfilerData::setState(QmlProfilerData::State state)
 564 {
 565     // It's not an error, we are continuously calling "AcquiringData" for example
 566     if (d->state == state)
 567         return;
 568
 569     switch (state) {
 570     case Empty:
 571         // if it's not empty, complain but go on
 572         if (!isEmpty())
 573             emit error("Invalid qmlprofiler state change (Empty)");
 574         break;
 575     case AcquiringData:
 576         // we're not supposed to receive new data while processing older data
 577         if (d->state == ProcessingData)
 578             emit error("Invalid qmlprofiler state change (AcquiringData)");
 579         break;
 580     case ProcessingData:
 581         if (d->state != AcquiringData)
 582             emit error("Invalid qmlprofiler state change (ProcessingData)");
 583         break;
 584     case Done:
 585         if (d->state != ProcessingData && d->state != Empty)
 586             emit error("Invalid qmlprofiler state change (Done)");
 587         break;
 588     default:
 589         emit error("Trying to set unknown state in events list");
 590         break;
 591     }
 592
 593     d->state = state;
 594     emit stateChanged();
 595
 596     // special: if we were done with an empty list, clean internal data and go back to empty
 597     if (d->state == Done && isEmpty()) {
 598         clear();
 599     }
 600     return;
 601 }
 602