From 5f3ddb80c602d94d5661caf853500608c2d1eff4 Mon Sep 17 00:00:00 2001 From: Eelke Klein Date: Sun, 8 Jan 2017 15:16:16 +0100 Subject: [PATCH] Show elapsed time during queries and show execute and plan time above query explain. --- Ivory.pro | 2 +- mainwindow.cpp | 115 +++++++++++++++++++++++++++++++++++++++++++++++- mainwindow.h | 10 +++++ mainwindow.ui | 39 +++++++++++++++- ui_mainwindow.h | 35 ++++++++++++++- 5 files changed, 194 insertions(+), 7 deletions(-) diff --git a/Ivory.pro b/Ivory.pro index 48c68fe..9a355b0 100644 --- a/Ivory.pro +++ b/Ivory.pro @@ -12,7 +12,7 @@ TARGET = Ivory TEMPLATE = app INCLUDEPATH += C:\prog\include -DEFINES += WIN32_LEAN_AND_MEAN +DEFINES += WIN32_LEAN_AND_MEAN NOMINMAX LIBS += c:\prog\lib\libpq.lib User32.lib SOURCES += main.cpp\ diff --git a/mainwindow.cpp b/mainwindow.cpp index 2a4236c..e4dd559 100644 --- a/mainwindow.cpp +++ b/mainwindow.cpp @@ -9,9 +9,61 @@ #include #include "json/json.h" #include "explaintreemodelitem.h" +#include //#include +namespace { + + // Supported range from microseconds to seconds + // min:sec to hours::min::sec + QString msfloatToHumanReadableString(float ms) + { + QString unit; + float val; + int deci = 3; + if (ms < 1.0f) { + val = ms * 1000.f; + //result = QString::asprintf("%0.3f", ms * 1000.0f); + unit = u8"μs"; + } + else if (ms >= 1000.0) { + val = ms / 1000.0f; + unit = "s"; + if (val >= 60.0) { + int secs = val; + int min = secs / 60.0; + secs -= min * 60; + if (min >= 60) { + int hour = min / 60; + min -= hour * 60; + return QString::asprintf("%d:%02d:%02d", hour, min, secs); + } + else { + return QString::asprintf("%02d:%02d", min, secs); + } + } + } + else { + val = ms; + unit = "ms"; + } + + if (val >= 1000.f) { + deci = 0; + } + else if (val >= 100.f) { + deci = 1; + } + else if (val >= 10.f) { + deci = 2; + } + QString result = QString::asprintf("%0.*f", deci, val); + return result + unit; + } + +} + namespace pg = Pgsql; const char * test_query = @@ -63,6 +115,9 @@ MainWindow::MainWindow(QWidget *parent) { QueueTask([this, details]() { receiveNotice(details); }); }); + + m_timeElapsedLabel = new QLabel(this); + statusBar()->addPermanentWidget(m_timeElapsedLabel); } MainWindow::~MainWindow() @@ -111,6 +166,7 @@ void MainWindow::connectionStateChanged(ASyncDBConnection::State state) status_str = tr("Query geannuleerd"); break; } + addLog(status_str); statusBar()->showMessage(status_str); } @@ -122,12 +178,15 @@ void MainWindow::startConnect() void MainWindow::performQuery() { + addLog("Query clicked"); + ui->ResultView->setModel(nullptr); resultModel.reset(); ui->messagesEdit->clear(); QString command = ui->queryEdit->toPlainText(); std::string cmd = command.toUtf8().data(); + startTimer(); m_dbConnection.send(cmd, [this](std::shared_ptr res) { @@ -137,7 +196,9 @@ void MainWindow::performQuery() void MainWindow::query_ready(std::shared_ptr dbres) { + endTimer(); if (dbres) { + addLog("query_ready with result"); auto st = dbres->resultStatus(); if (st == PGRES_TUPLES_OK) { resultModel.reset(new QueryResultModel(nullptr , dbres)); @@ -179,16 +240,20 @@ void MainWindow::query_ready(std::shared_ptr dbres) } } else { + addLog("query_ready with NO result"); statusBar()->showMessage(tr("Query cancelled.")); } } void MainWindow::performExplain() { - ui->ResultView->setModel(nullptr); - resultModel.reset(); + ui->explainTreeView->setModel(nullptr); + explainModel.reset(); ui->messagesEdit->clear(); + addLog("Explain clicked"); + + startTimer(); QString command = "EXPLAIN (ANALYZE, VERBOSE, BUFFERS, FORMAT JSON) "; command += ui->queryEdit->toPlainText(); std::string cmd = command.toUtf8().data(); @@ -217,7 +282,14 @@ void MainWindow::performExplain() void MainWindow::explain_ready(ExplainRoot::SPtr explain) { + endTimer(); if (explain) { + addLog("Explain ready"); + QString times_str = QString("Execution time: %1, Planning time: %2") + .arg( + msfloatToHumanReadableString(explain->executionTime) + , msfloatToHumanReadableString(explain->planningTime)); + ui->lblTimes->setText(times_str); explainModel.reset(new QueryExplainModel(nullptr, explain)); ui->explainTreeView->setModel(explainModel.get()); ui->explainTreeView->expandAll(); @@ -231,6 +303,7 @@ void MainWindow::explain_ready(ExplainRoot::SPtr explain) statusBar()->showMessage(tr("Explain ready.")); } else { + addLog("Explain no result"); statusBar()->showMessage(tr("Explain failed.")); } } @@ -259,3 +332,41 @@ void MainWindow::receiveNotice(Pgsql::ErrorDetails notice) table->cellAt(3, 1).firstCursorPosition().insertText(QString::fromStdString(notice.messageDetail)); } } + +void MainWindow::addLog(QString s) +{ + QTextCursor text_cursor = QTextCursor(ui->edtLog->document()); + text_cursor.movePosition(QTextCursor::End); + text_cursor.insertText(s + "\r\n"); +} + +void MainWindow::startTimer() +{ + m_startTime = std::chrono::steady_clock::now(); + m_timer = std::make_unique(nullptr); + m_timer->setTimerType(Qt::CoarseTimer); + connect(m_timer.get(), SIGNAL(timeout()), this, SLOT(updateTimer())); + m_timer->start(18); +} + +void MainWindow::updateTimer() +{ + auto nu = std::chrono::steady_clock::now(); + std::chrono::duration diff = nu - m_startTime; + m_timeElapsedLabel->setText(msfloatToHumanReadableString(diff.count())); + + if (m_timer) { + int interval = int(diff.count()) / 25; + interval = std::max(interval, 18); + interval = std::min(interval, 1000); + m_timer->start(interval); + } +} + +void MainWindow::endTimer() +{ + if (m_timer) { + m_timer.reset(); + updateTimer(); + } +} diff --git a/mainwindow.h b/mainwindow.h index bea7b72..1c3fe43 100644 --- a/mainwindow.h +++ b/mainwindow.h @@ -3,6 +3,7 @@ #include "asyncdbconnection.h" #include "tsqueue.h" +#include #include #include #include @@ -48,6 +49,12 @@ public: private: TSQueue m_taskQueue; + QLabel *m_timeElapsedLabel; + std::unique_ptr m_timer; + std::chrono::time_point m_startTime; + + void startTimer(); + void endTimer(); std::unique_ptr ui; @@ -73,6 +80,9 @@ private slots: void receiveNotice(Pgsql::ErrorDetails notice); void processCallableQueue(); + + void addLog(QString s); + void updateTimer(); }; #endif // MAINWINDOW_H diff --git a/mainwindow.ui b/mainwindow.ui index f2c9d9a..fe06e4c 100644 --- a/mainwindow.ui +++ b/mainwindow.ui @@ -38,7 +38,7 @@ - 1 + 2 @@ -91,12 +91,24 @@ 10 + + QAbstractItemView::NoEditTriggers + + + true + QAbstractItemView::ScrollPerPixel QAbstractItemView::ScrollPerPixel + + false + + + 20 + @@ -118,7 +130,7 @@ 2 - + QAbstractItemView::NoEditTriggers @@ -126,14 +138,37 @@ false + + true + 10 + + false + false + + + + + + + + + + + + Log + + + + + diff --git a/ui_mainwindow.h b/ui_mainwindow.h index e5ecbc2..2dbdaed 100644 --- a/ui_mainwindow.h +++ b/ui_mainwindow.h @@ -15,10 +15,12 @@ #include #include #include +#include #include #include #include #include +#include #include #include #include @@ -49,6 +51,10 @@ public: QWidget *explainTab; QGridLayout *gridLayout_3; QTreeView *explainTreeView; + QLabel *lblTimes; + QWidget *logTab; + QVBoxLayout *verticalLayout_2; + QPlainTextEdit *edtLog; QMenuBar *menuBar; QMenu *menuTest; QToolBar *mainToolBar; @@ -106,8 +112,12 @@ public: font.setFamily(QStringLiteral("Source Sans Pro")); font.setPointSize(10); ResultView->setFont(font); + ResultView->setEditTriggers(QAbstractItemView::NoEditTriggers); + ResultView->setAlternatingRowColors(true); ResultView->setVerticalScrollMode(QAbstractItemView::ScrollPerPixel); ResultView->setHorizontalScrollMode(QAbstractItemView::ScrollPerPixel); + ResultView->setWordWrap(false); + ResultView->verticalHeader()->setMinimumSectionSize(20); gridLayout->addWidget(ResultView, 0, 0, 1, 1); @@ -123,12 +133,31 @@ public: explainTreeView->setObjectName(QStringLiteral("explainTreeView")); explainTreeView->setEditTriggers(QAbstractItemView::NoEditTriggers); explainTreeView->setProperty("showDropIndicator", QVariant(false)); + explainTreeView->setAlternatingRowColors(true); explainTreeView->setIndentation(10); + explainTreeView->setUniformRowHeights(false); explainTreeView->header()->setStretchLastSection(false); - gridLayout_3->addWidget(explainTreeView, 0, 0, 1, 1); + gridLayout_3->addWidget(explainTreeView, 1, 0, 1, 1); + + lblTimes = new QLabel(explainTab); + lblTimes->setObjectName(QStringLiteral("lblTimes")); + + gridLayout_3->addWidget(lblTimes, 0, 0, 1, 1); tabWidget->addTab(explainTab, QString()); + logTab = new QWidget(); + logTab->setObjectName(QStringLiteral("logTab")); + verticalLayout_2 = new QVBoxLayout(logTab); + verticalLayout_2->setSpacing(6); + verticalLayout_2->setContentsMargins(11, 11, 11, 11); + verticalLayout_2->setObjectName(QStringLiteral("verticalLayout_2")); + edtLog = new QPlainTextEdit(logTab); + edtLog->setObjectName(QStringLiteral("edtLog")); + + verticalLayout_2->addWidget(edtLog); + + tabWidget->addTab(logTab, QString()); splitter->addWidget(tabWidget); verticalLayout->addWidget(splitter); @@ -151,7 +180,7 @@ public: retranslateUi(MainWindow); - tabWidget->setCurrentIndex(1); + tabWidget->setCurrentIndex(2); QMetaObject::connectSlotsByName(MainWindow); @@ -162,7 +191,9 @@ public: MainWindow->setWindowTitle(QApplication::translate("MainWindow", "MainWindow", Q_NULLPTR)); tabWidget->setTabText(tabWidget->indexOf(messageTab), QApplication::translate("MainWindow", "Messages", Q_NULLPTR)); tabWidget->setTabText(tabWidget->indexOf(dataTab), QApplication::translate("MainWindow", "Data", Q_NULLPTR)); + lblTimes->setText(QString()); tabWidget->setTabText(tabWidget->indexOf(explainTab), QApplication::translate("MainWindow", "Explain", Q_NULLPTR)); + tabWidget->setTabText(tabWidget->indexOf(logTab), QApplication::translate("MainWindow", "Log", Q_NULLPTR)); menuTest->setTitle(QApplication::translate("MainWindow", "test", Q_NULLPTR)); } // retranslateUi