From 9e070f9bce237ebcf4270a2c500a390a47979828 Mon Sep 17 00:00:00 2001 From: ispyisail Date: Mon, 27 Jul 2026 17:37:49 +1200 Subject: [PATCH] Log project load times, split by phase Requested in #553 to compare Qt5 and Qt6 builds. QET already reports how long the elements collection takes to load (ElementsCollectionWidget:: reload); this adds the equivalent for opening a project. The phases are reported separately rather than as a single total. Reading the XML and building the objects is mostly independent of the Qt version, whereas refreshing the diagrams is graphics-scene work -- a single number would mix the two and could suggest a Qt version makes no difference when the part that changed is simply not where the time goes. Measured on the example projects, XML parsing is 3-7% of the total and diagram construction 77-83%, so the distinction matters in practice. QETProject::openFile() reports the total with the parse/build split, and readProjectXml() reports the build phases: Project content built in 1.391 seconds (elements collection 0.009, diagrams 1.153, terminal strips 0, refresh 0.196, database 0.033) Project "example.qet" (3399 KiB) opened in 1.505 seconds (xml parsing 0.11, content 1.395) Logged with qInfo(), matching the existing collection timer, so it lands in the normal log without a debug build. Co-Authored-By: Claude Opus 5 --- sources/qetproject.cpp | 38 +++++++++++++++++++++++++++++++++++++- 1 file changed, 37 insertions(+), 1 deletion(-) diff --git a/sources/qetproject.cpp b/sources/qetproject.cpp index 679adf826..ca8a64cd3 100644 --- a/sources/qetproject.cpp +++ b/sources/qetproject.cpp @@ -35,6 +35,7 @@ #include "qetxml.h" #include "qetversion.h" +#include #include #include #include @@ -227,6 +228,9 @@ void QETProject::init() */ QETProject::ProjectState QETProject::openFile(QFile *file) { + QElapsedTimer load_timer; + load_timer.start(); + bool opened_here = file->isOpen() ? false : true; if (!file->isOpen() && !file->open(QIODevice::ReadOnly @@ -245,10 +249,19 @@ QETProject::ProjectState QETProject::openFile(QFile *file) } return XmlParsingFailed; } + const qint64 xml_parse_ms = load_timer.elapsed(); //Build the project from the xml readProjectXml(xml_project); + const qint64 total_ms = load_timer.elapsed(); + qInfo().nospace().noquote() + << "Project \"" << fi.fileName() << "\" (" + << fi.size() / 1024 << " KiB) opened in " + << total_ms / 1000.0 << " seconds (xml parsing " + << xml_parse_ms / 1000.0 << ", content " + << (total_ms - xml_parse_ms) / 1000.0 << ")"; + if (!fi.isWritable()) { setReadOnly(true); } @@ -1489,21 +1502,44 @@ void QETProject::readProjectXml(QDomDocument &xml_project) //load the embedded titleblock templates m_titleblocks_collection.fromXml(xml_project.documentElement()); + /* Timings of the phases below are logged so the cost of opening a + * project can be attributed. Reading the XML and building the objects + * is mostly independent of the Qt version, while refreshing the + * diagrams is graphics-scene work -- keeping them apart is what makes + * the numbers comparable between builds. + */ + QElapsedTimer phase_timer; + phase_timer.start(); + //Load the embedded elements collection readElementsCollectionXml(xml_project); + const qint64 elements_ms = phase_timer.restart(); //Load the diagrams readDiagramsXml(xml_project); + const qint64 diagrams_ms = phase_timer.restart(); //Load the terminal strip readTerminalStripXml(xml_project); + const qint64 strips_ms = phase_timer.restart(); //Now that all are loaded we refresh content of the project. refresh(); - + const qint64 refresh_ms = phase_timer.restart(); m_data_base.blockSignals(false); m_data_base.updateDB(); + const qint64 database_ms = phase_timer.elapsed(); + + qInfo().nospace() + << "Project content built in " + << (elements_ms + diagrams_ms + strips_ms + + refresh_ms + database_ms) / 1000.0 + << " seconds (elements collection " << elements_ms / 1000.0 + << ", diagrams " << diagrams_ms / 1000.0 + << ", terminal strips " << strips_ms / 1000.0 + << ", refresh " << refresh_ms / 1000.0 + << ", database " << database_ms / 1000.0 << ")"; m_state = Ok; }