From 1ee8d0fb64b4a7c59fa4601fc8cad41372a8dd19 Mon Sep 17 00:00:00 2001 From: Ulf Hermann Date: Mon, 20 Feb 2017 18:55:45 +0100 Subject: [PATCH] QmlProfiler: Improve error and progress handling for loading and saving * Clear the trace and send the loadingFinished() signal when loading fails or is canceled. loadingFinished() re-enables the UI, which is in fact important. * Check more consistently for whether the operation was canceled and add a separate signal for that. * When saving fails or is canceled, remove the half-written file. * Don't try to guess the number of events for progress reporting when saving. Use the event timestamps and start/end time instead. * Properly initialize the progress range in all cases. * Drop the bool return value from the load methods. Nobody uses that. * Send loadFinished() only after loading a file, not every time we reach the Done state. Change-Id: I507f11c667e20534ea335e84798de11aa06fb6f2 Reviewed-by: Christian Kandeler Reviewed-by: Ulf Hermann --- .../qmlprofiler/qmlprofilermodelmanager.cpp | 38 +- .../qmlprofiler/qmlprofilertracefile.cpp | 365 +++++++++--------- .../qmlprofiler/qmlprofilertracefile.h | 21 +- 3 files changed, 240 insertions(+), 184 deletions(-) diff --git a/src/plugins/qmlprofiler/qmlprofilermodelmanager.cpp b/src/plugins/qmlprofiler/qmlprofilermodelmanager.cpp index 9c396910a71..f59c1c9a75d 100644 --- a/src/plugins/qmlprofiler/qmlprofilermodelmanager.cpp +++ b/src/plugins/qmlprofiler/qmlprofilermodelmanager.cpp @@ -369,8 +369,6 @@ void QmlProfilerModelManager::processingDone() d->notesModel->loadData(); setState(Done); - - emit loadFinished(); } void QmlProfilerModelManager::save(const QString &filename) @@ -394,6 +392,24 @@ void QmlProfilerModelManager::save(const QString &filename) connect(writer, &QObject::destroyed, this, &QmlProfilerModelManager::saveFinished, Qt::QueuedConnection); + connect(writer, &QmlProfilerFileWriter::error, this, [this, file](const QString &message) { + file->close(); + file->remove(); + delete file; + emit error(message); + }, Qt::QueuedConnection); + + connect(writer, &QmlProfilerFileWriter::success, this, [this, file]() { + file->close(); + delete file; + }, Qt::QueuedConnection); + + connect(writer, &QmlProfilerFileWriter::canceled, this, [this, file]() { + file->close(); + file->remove(); + delete file; + }, Qt::QueuedConnection); + QFuture result = Utils::runAsync([file, writer] (QFutureInterface &future) { writer->setFuture(&future); if (file->fileName().endsWith(QLatin1String(Constants::QtdFileExtension))) @@ -401,7 +417,6 @@ void QmlProfilerModelManager::save(const QString &filename) else writer->saveQzt(file); writer->deleteLater(); - file->deleteLater(); }); Core::ProgressManager::addTask(result, tr("Saving Trace Data"), Constants::TASK_SAVE, @@ -423,10 +438,8 @@ void QmlProfilerModelManager::load(const QString &filename) setState(AcquiringData); QmlProfilerFileReader *reader = new QmlProfilerFileReader(this); - connect(reader, &QmlProfilerFileReader::error, this, [this, reader](const QString &message) { - delete reader; - emit error(message); - }, Qt::QueuedConnection); + connect(reader, &QObject::destroyed, this, &QmlProfilerModelManager::loadFinished, + Qt::QueuedConnection); connect(reader, &QmlProfilerFileReader::typesLoaded, this, &QmlProfilerModelManager::addEventTypes); @@ -444,6 +457,17 @@ void QmlProfilerModelManager::load(const QString &filename) acquiringDone(); }, Qt::QueuedConnection); + connect(reader, &QmlProfilerFileReader::error, this, [this, reader](const QString &message) { + clear(); + delete reader; + emit error(message); + }, Qt::QueuedConnection); + + connect(reader, &QmlProfilerFileReader::canceled, this, [this, reader]() { + clear(); + delete reader; + }, Qt::QueuedConnection); + QFuture result = Utils::runAsync([isQtd, file, reader] (QFutureInterface &future) { reader->setFuture(&future); if (isQtd) diff --git a/src/plugins/qmlprofiler/qmlprofilertracefile.cpp b/src/plugins/qmlprofiler/qmlprofilertracefile.cpp index 5123902ef14..0551d0310ee 100644 --- a/src/plugins/qmlprofiler/qmlprofilertracefile.cpp +++ b/src/plugins/qmlprofiler/qmlprofilertracefile.cpp @@ -139,15 +139,13 @@ void QmlProfilerFileReader::setFuture(QFutureInterface *future) } } -bool QmlProfilerFileReader::loadQtd(QIODevice *device) +void QmlProfilerFileReader::loadQtd(QIODevice *device) { QXmlStreamReader stream(device); bool validVersion = true; - while (validVersion && !stream.atEnd() && !stream.hasError()) { - if (isCanceled()) - return false; + while (validVersion && !stream.atEnd() && !stream.hasError() && !isCanceled()) { QXmlStreamReader::TokenType token = stream.readNext(); const QStringRef elementName = stream.name(); switch (token) { @@ -188,16 +186,15 @@ bool QmlProfilerFileReader::loadQtd(QIODevice *device) } } - if (stream.hasError()) { + if (isCanceled()) + emit canceled(); + else if (stream.hasError()) emit error(tr("Error while parsing trace data file: %1").arg(stream.errorString())); - return false; - } else { + else emit success(); - return true; - } } -bool QmlProfilerFileReader::loadQzt(QIODevice *device) +void QmlProfilerFileReader::loadQzt(QIODevice *device) { QDataStream stream(device); stream.setVersion(QDataStream::Qt_5_5); @@ -206,7 +203,7 @@ bool QmlProfilerFileReader::loadQzt(QIODevice *device) stream >> magic; if (magic != QByteArray("QMLPROFILER")) { emit error(tr("Invalid magic: %1").arg(QLatin1String(magic))); - return false; + return; } qint32 dataStreamVersion; @@ -214,7 +211,7 @@ bool QmlProfilerFileReader::loadQzt(QIODevice *device) if (dataStreamVersion > QDataStream::Qt_DefaultCompiledVersion) { emit error(tr("Unknown data stream version: %1").arg(dataStreamVersion)); - return false; + return; } stream.setVersion(dataStreamVersion); @@ -226,45 +223,47 @@ bool QmlProfilerFileReader::loadQzt(QIODevice *device) QByteArray data; updateProgress(device); - stream >> data; - buffer.setData(qUncompress(data)); - buffer.open(QIODevice::ReadOnly); - bufferStream >> m_eventTypes; - buffer.close(); - emit typesLoaded(m_eventTypes); - updateProgress(device); + if (!isCanceled()) { + stream >> data; + buffer.setData(qUncompress(data)); + buffer.open(QIODevice::ReadOnly); + bufferStream >> m_eventTypes; + buffer.close(); + emit typesLoaded(m_eventTypes); + updateProgress(device); + } - stream >> data; - buffer.setData(qUncompress(data)); - buffer.open(QIODevice::ReadOnly); - bufferStream >> m_notes; - buffer.close(); - emit notesLoaded(m_notes); - updateProgress(device); + if (!isCanceled()) { + stream >> data; + buffer.setData(qUncompress(data)); + buffer.open(QIODevice::ReadOnly); + bufferStream >> m_notes; + buffer.close(); + emit notesLoaded(m_notes); + updateProgress(device); + } const int eventBufferLength = 1024; QVector eventBuffer(eventBufferLength); int eventBufferIndex = 0; - while (!stream.atEnd()) { + while (!stream.atEnd() && !isCanceled()) { stream >> data; buffer.setData(qUncompress(data)); buffer.open(QIODevice::ReadOnly); - while (!buffer.atEnd()) { - if (isCanceled()) - return false; + while (!buffer.atEnd() && !isCanceled()) { QmlEvent &event = eventBuffer[eventBufferIndex]; bufferStream >> event; if (bufferStream.status() == QDataStream::Ok) { if (event.typeIndex() >= m_eventTypes.length()) { emit error(tr("Invalid type index %1").arg(event.typeIndex())); - return false; + return; } m_loadedFeatures |= (1ULL << m_eventTypes[event.typeIndex()].feature()); } else if (bufferStream.status() == QDataStream::ReadPastEnd) { break; // Apparently EOF is a character so we end up here after the last event. } else if (bufferStream.status() == QDataStream::ReadCorruptData) { emit error(tr("Corrupt data before position %1.").arg(device->pos())); - return false; + return; } else { Q_UNREACHABLE(); } @@ -276,10 +275,14 @@ bool QmlProfilerFileReader::loadQzt(QIODevice *device) buffer.close(); updateProgress(device); } - eventBuffer.resize(eventBufferIndex); - emit qmlEventsLoaded(eventBuffer); - emit success(); - return true; + + if (isCanceled()) { + emit canceled(); + } else { + eventBuffer.resize(eventBufferIndex); + emit qmlEventsLoaded(eventBuffer); + emit success(); + } } quint64 QmlProfilerFileReader::loadedFeatures() const @@ -309,9 +312,7 @@ void QmlProfilerFileReader::loadEventTypes(QXmlStreamReader &stream) line = column = 0; }; - while (!stream.atEnd() && !stream.hasError()) { - if (isCanceled()) - return; + while (!stream.atEnd() && !stream.hasError() && !isCanceled()) { QXmlStreamReader::TokenType token = stream.readNext(); const QStringRef elementName = stream.name(); @@ -424,9 +425,7 @@ void QmlProfilerFileReader::loadEvents(QXmlStreamReader &stream) QTC_ASSERT(stream.name() == _("profilerDataModel"), return); QVector events; - while (!stream.atEnd() && !stream.hasError()) { - if (isCanceled()) - return; + while (!stream.atEnd() && !stream.hasError() && !isCanceled()) { QXmlStreamReader::TokenType token = stream.readNext(); const QStringRef elementName = stream.name(); @@ -514,9 +513,7 @@ void QmlProfilerFileReader::loadEvents(QXmlStreamReader &stream) void QmlProfilerFileReader::loadNotes(QXmlStreamReader &stream) { QmlNote currentNote; - while (!stream.atEnd() && !stream.hasError()) { - if (isCanceled()) - return; + while (!stream.atEnd() && !stream.hasError() && !isCanceled()) { QXmlStreamReader::TokenType token = stream.readNext(); const QStringRef elementName = stream.name(); @@ -596,16 +593,14 @@ void QmlProfilerFileWriter::setNotes(const QVector ¬es) void QmlProfilerFileWriter::setFuture(QFutureInterface *future) { m_future = future; + if (m_future) { + m_future->setProgressRange(0, ProgressTotal); + m_future->setProgressValue(0); + } } void QmlProfilerFileWriter::saveQtd(QIODevice *device) { - if (m_future) { - m_future->setProgressRange(0, qMax(m_model->eventTypes().size() + m_notes.size(), 1)); - m_future->setProgressValue(0); - m_newProgressValue = 0; - } - QXmlStreamWriter stream(device); stream.setAutoFormatting(true); @@ -619,11 +614,9 @@ void QmlProfilerFileWriter::saveQtd(QIODevice *device) stream.writeStartElement(_("eventData")); stream.writeAttribute(_("totalTime"), QString::number(m_measuredTime)); - const QVector &eventTypes = m_model->eventTypes(); - for (int typeIndex = 0, end = eventTypes.length(); typeIndex < end; ++typeIndex) { - if (isCanceled()) - return; + for (int typeIndex = 0, end = eventTypes.length(); typeIndex < end && !isCanceled(); + ++typeIndex) { const QmlEventType &type = eventTypes[typeIndex]; @@ -667,107 +660,118 @@ void QmlProfilerFileWriter::saveQtd(QIODevice *device) stream.writeTextElement(_("level"), QString::number(type.detailType())); } stream.writeEndElement(); - incrementProgress(); } + updateProgress(ProgressTypes); stream.writeEndElement(); // eventData - stream.writeStartElement(_("profilerDataModel")); + if (!isCanceled()) { + stream.writeStartElement(_("profilerDataModel")); - QStack stack; - m_model->replayEvents(-1, -1, [this, &stack, &stream](const QmlEvent &event, - const QmlEventType &type) { - if (isCanceled()) - return; + QStack stack; + m_model->replayEvents(-1, -1, [this, &stack, &stream](const QmlEvent &event, + const QmlEventType &type) { + if (isCanceled()) + return; - if (type.rangeType() != MaximumRangeType && event.rangeStage() == RangeStart) { - stack.push(event); - return; - } - - stream.writeStartElement(_("range")); - if (type.rangeType() != MaximumRangeType && event.rangeStage() == RangeEnd) { - QmlEvent start = stack.pop(); - stream.writeAttribute(_("startTime"), QString::number(start.timestamp())); - stream.writeAttribute(_("duration"), - QString::number(event.timestamp() - start.timestamp())); - } else { - stream.writeAttribute(_("startTime"), QString::number(event.timestamp())); - } - - stream.writeAttribute(_("eventIndex"), QString::number(event.typeIndex())); - - if (type.message() == Event) { - if (type.detailType() == AnimationFrame) { - // special: animation event - stream.writeAttribute(_("framerate"), QString::number(event.number(0))); - stream.writeAttribute(_("animationcount"), - QString::number(event.number(1))); - stream.writeAttribute(_("thread"), QString::number(event.number(2))); - } else if (type.detailType() == Key || type.detailType() == Mouse) { - // special: input event - stream.writeAttribute(_("type"), QString::number(event.number(0))); - stream.writeAttribute(_("data1"), QString::number(event.number(1))); - stream.writeAttribute(_("data2"), QString::number(event.number(2))); - } - } - - // special: pixmap cache event - if (type.message() == PixmapCacheEvent) { - if (type.detailType() == PixmapSizeKnown) { - stream.writeAttribute(_("width"), QString::number(event.number(0))); - stream.writeAttribute(_("height"), QString::number(event.number(1))); + if (type.rangeType() != MaximumRangeType && event.rangeStage() == RangeStart) { + stack.push(event); + return; } - if (type.detailType() == PixmapReferenceCountChanged - || type.detailType() == PixmapCacheCountChanged) - stream.writeAttribute(_("refCount"), QString::number(event.number(2))); - } - - if (type.message() == SceneGraphFrame) { - // special: scenegraph frame events - for (int i = 0; i < 5; ++i) { - qint64 number = event.number(i); - if (number <= 0) - continue; - stream.writeAttribute(QString::fromLatin1("timing%1").arg(i + 1), - QString::number(number)); + stream.writeStartElement(_("range")); + if (type.rangeType() != MaximumRangeType && event.rangeStage() == RangeEnd) { + QmlEvent start = stack.pop(); + stream.writeAttribute(_("startTime"), QString::number(start.timestamp())); + stream.writeAttribute(_("duration"), + QString::number(event.timestamp() - start.timestamp())); + } else { + stream.writeAttribute(_("startTime"), QString::number(event.timestamp())); } - } - // special: memory allocation event - if (type.message() == MemoryAllocation) - stream.writeAttribute(_("amount"), QString::number(event.number(0))); + stream.writeAttribute(_("eventIndex"), QString::number(event.typeIndex())); - if (type.message() == DebugMessage) - stream.writeAttribute(_("text"), event.string()); + if (type.message() == Event) { + if (type.detailType() == AnimationFrame) { + // special: animation event + stream.writeAttribute(_("framerate"), QString::number(event.number(0))); + stream.writeAttribute(_("animationcount"), + QString::number(event.number(1))); + stream.writeAttribute(_("thread"), QString::number(event.number(2))); + } else if (type.detailType() == Key || type.detailType() == Mouse) { + // special: input event + stream.writeAttribute(_("type"), QString::number(event.number(0))); + stream.writeAttribute(_("data1"), QString::number(event.number(1))); + stream.writeAttribute(_("data2"), QString::number(event.number(2))); + } + } - stream.writeEndElement(); - incrementProgress(); - }); - stream.writeEndElement(); // profilerDataModel + // special: pixmap cache event + if (type.message() == PixmapCacheEvent) { + if (type.detailType() == PixmapSizeKnown) { + stream.writeAttribute(_("width"), QString::number(event.number(0))); + stream.writeAttribute(_("height"), QString::number(event.number(1))); + } - stream.writeStartElement(_("noteData")); - for (int noteIndex = 0; noteIndex < m_notes.size(); ++noteIndex) { - if (isCanceled()) - return; + if (type.detailType() == PixmapReferenceCountChanged + || type.detailType() == PixmapCacheCountChanged) + stream.writeAttribute(_("refCount"), QString::number(event.number(2))); + } - const QmlNote ¬e = m_notes[noteIndex]; - stream.writeStartElement(_("note")); - stream.writeAttribute(_("startTime"), QString::number(note.startTime())); - stream.writeAttribute(_("duration"), QString::number(note.duration())); - stream.writeAttribute(_("eventIndex"), QString::number(note.typeIndex())); - stream.writeAttribute(_("collapsedRow"), QString::number(note.collapsedRow())); - stream.writeCharacters(note.text()); - stream.writeEndElement(); // note - incrementProgress(); + if (type.message() == SceneGraphFrame) { + // special: scenegraph frame events + for (int i = 0; i < 5; ++i) { + qint64 number = event.number(i); + if (number <= 0) + continue; + stream.writeAttribute(QString::fromLatin1("timing%1").arg(i + 1), + QString::number(number)); + } + } + + // special: memory allocation event + if (type.message() == MemoryAllocation) + stream.writeAttribute(_("amount"), QString::number(event.number(0))); + + if (type.message() == DebugMessage) + stream.writeAttribute(_("text"), event.string()); + + stream.writeEndElement(); + + // Update the progress roughly every 4k events. It doesn't have to be precise. + if ((event.timestamp() & 0xfff) == 0) + updateProgress(event.timestamp()); + }); + + stream.writeEndElement(); // profilerDataModel } - stream.writeEndElement(); // noteData - if (isCanceled()) - return; + if (!isCanceled()) { + stream.writeStartElement(_("noteData")); + for (int noteIndex = 0; noteIndex < m_notes.size() && !isCanceled(); ++noteIndex) { + + const QmlNote ¬e = m_notes[noteIndex]; + stream.writeStartElement(_("note")); + stream.writeAttribute(_("startTime"), QString::number(note.startTime())); + stream.writeAttribute(_("duration"), QString::number(note.duration())); + stream.writeAttribute(_("eventIndex"), QString::number(note.typeIndex())); + stream.writeAttribute(_("collapsedRow"), QString::number(note.collapsedRow())); + stream.writeCharacters(note.text()); + stream.writeEndElement(); // note + } + stream.writeEndElement(); // noteData + updateProgress(ProgressNotes); + } stream.writeEndElement(); // trace stream.writeEndDocument(); + + if (isCanceled()) { + emit canceled(); + } else if (stream.hasError()) { + emit error(tr("Error writing trace file.")); + } else { + emit success(); + } } void QmlProfilerFileWriter::saveQzt(QFile *file) @@ -784,47 +788,64 @@ void QmlProfilerFileWriter::saveQzt(QFile *file) QDataStream bufferStream(&buffer); buffer.open(QIODevice::WriteOnly); - incrementProgress(); - buffer.open(QIODevice::WriteOnly); - bufferStream << m_model->eventTypes(); - stream << qCompress(buffer.data()); - buffer.close(); - buffer.buffer().clear(); - incrementProgress(); - buffer.open(QIODevice::WriteOnly); - bufferStream << m_notes; - stream << qCompress(buffer.data()); - buffer.close(); - buffer.buffer().clear(); - incrementProgress(); + if (!isCanceled()) { + bufferStream << m_model->eventTypes(); + stream << qCompress(buffer.data()); + buffer.close(); + buffer.buffer().clear(); + updateProgress(ProgressTypes); + } - buffer.open(QIODevice::WriteOnly); - m_model->replayEvents(-1, -1, [&stream, &buffer, &bufferStream](const QmlEvent &event, - const QmlEventType &type) { - Q_UNUSED(type); - bufferStream << event; - // 32MB buffer should be plenty for efficient compression - if (buffer.data().length() > (1 << 25)) { - stream << qCompress(buffer.data()); - buffer.close(); - buffer.buffer().clear(); - buffer.open(QIODevice::WriteOnly); - } - }); - stream << qCompress(buffer.data()); - buffer.close(); - buffer.buffer().clear(); + if (!isCanceled()) { + buffer.open(QIODevice::WriteOnly); + bufferStream << m_notes; + stream << qCompress(buffer.data()); + buffer.close(); + buffer.buffer().clear(); + updateProgress(ProgressNotes); + } + + if (!isCanceled()) { + buffer.open(QIODevice::WriteOnly); + m_model->replayEvents(-1, -1, [this, &stream, &buffer, &bufferStream]( + const QmlEvent &event, const QmlEventType &type) { + Q_UNUSED(type); + bufferStream << event; + // 32MB buffer should be plenty for efficient compression + if (buffer.data().length() > (1 << 25)) { + stream << qCompress(buffer.data()); + buffer.close(); + buffer.buffer().clear(); + if (isCanceled()) + return; + buffer.open(QIODevice::WriteOnly); + updateProgress(event.timestamp()); + } + }); + } + + if (isCanceled()) { + emit canceled(); + } else { + stream << qCompress(buffer.data()); + buffer.close(); + buffer.buffer().clear(); + updateProgress(m_endTime); + emit success(); + } } -void QmlProfilerFileWriter::incrementProgress() +void QmlProfilerFileWriter::updateProgress(qint64 timestamp) { if (!m_future) return; - m_newProgressValue++; - if (float(m_newProgressValue - m_future->progressValue()) - / float(m_future->progressMaximum() - m_future->progressMinimum()) >= 0.01) { - m_future->setProgressValue(m_newProgressValue); + if (timestamp < 0) { + m_future->setProgressValue(m_future->progressValue() - timestamp); + } else { + m_future->setProgressValue(m_future->progressValue() + + float(m_endTime - timestamp) / float(m_endTime - m_startTime) + * ProgressEvents); } } diff --git a/src/plugins/qmlprofiler/qmlprofilertracefile.h b/src/plugins/qmlprofiler/qmlprofilertracefile.h index b705f07e689..b3d9bbc47b0 100644 --- a/src/plugins/qmlprofiler/qmlprofilertracefile.h +++ b/src/plugins/qmlprofiler/qmlprofilertracefile.h @@ -51,8 +51,8 @@ public: void setFuture(QFutureInterface *future); - bool loadQtd(QIODevice *device); - bool loadQzt(QIODevice *device); + void loadQtd(QIODevice *device); + void loadQzt(QIODevice *device); quint64 loadedFeatures() const; @@ -65,6 +65,7 @@ signals: void qmlEventsLoaded(const QVector &event); void error(const QString &error); void success(); + void canceled(); private: void loadEventTypes(QXmlStreamReader &reader); @@ -96,16 +97,26 @@ public: void saveQtd(QIODevice *device); void saveQzt(QFile *file); +signals: + void error(const QString &error); + void success(); + void canceled(); + private: - void calculateMeasuredTime(); - void incrementProgress(); + void updateProgress(qint64 timestamp); bool isCanceled() const; + enum ProgressValues { + ProgressTypes = -128, + ProgressNotes = -32, + ProgressEvents = 1024, + ProgressTotal = ProgressEvents - ProgressTypes - ProgressNotes + }; + qint64 m_startTime, m_endTime, m_measuredTime; QFutureInterface *m_future; const QmlProfilerDataModel *m_model; QVector m_notes; - int m_newProgressValue; };