From 82b98c07d17e8c5443fcd931ad2a835581ce0c16 Mon Sep 17 00:00:00 2001 From: Adriano dos Santos Fernandes Date: Fri, 10 Jun 2022 22:14:36 -0300 Subject: [PATCH] Add TOTAL_TIME column to PLG$PROF_REQUESTS. Add view PLG$PROF_STATEMENT_STATS_VIEW. --- doc/sql.extensions/README.profiler.md | 47 ++++++++++++++++-- src/include/firebird/FirebirdInterface.idl | 2 +- src/include/firebird/IdlFbInterfaces.h | 12 ++--- src/include/gen/Firebird.pas | 14 +++--- src/jrd/ProfilerManager.cpp | 4 +- src/jrd/ProfilerManager.h | 2 +- src/jrd/exe.cpp | 23 ++++++--- src/jrd/req.h | 1 + src/plugins/profiler/Profiler.cpp | 58 ++++++++++++++++++++-- 9 files changed, 132 insertions(+), 31 deletions(-) diff --git a/doc/sql.extensions/README.profiler.md b/doc/sql.extensions/README.profiler.md index 3818f1b121..188fa50169 100644 --- a/doc/sql.extensions/README.profiler.md +++ b/doc/sql.extensions/README.profiler.md @@ -266,6 +266,7 @@ Below is the list of tables that stores profile data. - `CALLER_REQUEST_ID` type `BIGINT` - Caller request ID - `START_TIMESTAMP` type `TIMESTAMP WITH TIME ZONE` - Moment this request was first gathered profile data - `FINISH_TIMESTAMP` type `TIMESTAMP WITH TIME ZONE` - Moment this request was finished + - `TOTAL_TIME` type `BIGINT` - Accumulated execution time (in nanoseconds) of the request - Primary key: `PROFILE_ID, REQUEST_ID` ## Table `PLG$PROF_PSQL_STATS` @@ -275,10 +276,10 @@ Below is the list of tables that stores profile data. - `LINE_NUM` type `INTEGER` - Line number of the statement - `COLUMN_NUM` type `INTEGER` - Column number of the statement - `STATEMENT_ID` type `BIGINT` - Statement ID - - `COUNTER` type `BIGINT` - Number of executed times of the statement - - `MIN_TIME` type `BIGINT` - Minimal time (in nanoseconds) of a statement execution - - `MAX_TIME` type `BIGINT` - Maximum time (in nanoseconds) of a statement execution - - `TOTAL_TIME` type `BIGINT` - Accumulated execution time (in nanoseconds) of the statement + - `COUNTER` type `BIGINT` - Number of executed times of the line/column + - `MIN_TIME` type `BIGINT` - Minimal time (in nanoseconds) of a line/column execution + - `MAX_TIME` type `BIGINT` - Maximum time (in nanoseconds) of a line/column execution + - `TOTAL_TIME` type `BIGINT` - Accumulated execution time (in nanoseconds) of the line/column - Primary key: `PROFILE_ID, REQUEST_ID, LINE_NUM, COLUMN_NUM` ## Table `PLG$PROF_RECORD_SOURCE_STATS` @@ -306,6 +307,44 @@ They should be the preferred way to analyze the collected data. They can also be After hot spots are found, one can drill down in the data at the request level through the tables. +## View `PLG$PROF_STATEMENT_STATS_VIEW` +``` +select req.profile_id, + req.statement_id, + sta.statement_type, + sta.package_name, + sta.routine_name, + sta.parent_statement_id, + sta_parent.statement_type parent_statement_type, + sta_parent.routine_name parent_routine_name, + (select sql_text + from plg$prof_statements + where profile_id = req.profile_id and + statement_id = coalesce(sta.parent_statement_id, req.statement_id) + ) sql_text, + count(*) counter, + min(req.total_time) min_time, + max(req.total_time) max_time, + sum(req.total_time) total_time, + sum(req.total_time) / count(*) avg_time + from plg$prof_requests req + join plg$prof_statements sta + on sta.profile_id = req.profile_id and + sta.statement_id = req.statement_id + left join plg$prof_statements sta_parent + on sta_parent.profile_id = sta.profile_id and + sta_parent.statement_id = sta.parent_statement_id + group by req.profile_id, + req.statement_id, + sta.statement_type, + sta.package_name, + sta.routine_name, + sta.parent_statement_id, + sta_parent.statement_type, + sta_parent.routine_name + order by sum(req.total_time) desc +``` + ## View `PLG$PROF_PSQL_STATS_VIEW` ``` select pstat.profile_id, diff --git a/src/include/firebird/FirebirdInterface.idl b/src/include/firebird/FirebirdInterface.idl index 30a535868b..743a295421 100644 --- a/src/include/firebird/FirebirdInterface.idl +++ b/src/include/firebird/FirebirdInterface.idl @@ -1734,7 +1734,7 @@ interface ProfilerSession : Disposable void onRequestStart(Status status, int64 requestId, int64 statementId, int64 callerRequestId, ISC_TIMESTAMP_TZ timestamp); - void onRequestFinish(Status status, int64 requestId, ISC_TIMESTAMP_TZ timestamp); + void onRequestFinish(Status status, int64 requestId, ISC_TIMESTAMP_TZ timestamp, uint64 runTime); void beforePsqlLineColumn(int64 requestId, uint line, uint column); void afterPsqlLineColumn(int64 requestId, uint line, uint column, uint64 runTime); diff --git a/src/include/firebird/IdlFbInterfaces.h b/src/include/firebird/IdlFbInterfaces.h index e07e3ee34e..bbfdada3af 100644 --- a/src/include/firebird/IdlFbInterfaces.h +++ b/src/include/firebird/IdlFbInterfaces.h @@ -6701,7 +6701,7 @@ namespace Firebird void (CLOOP_CARG *defineStatement)(IProfilerSession* self, IStatus* status, ISC_INT64 statementId, ISC_INT64 parentStatementId, const char* type, const char* packageName, const char* routineName, const char* sqlText) throw(); void (CLOOP_CARG *defineRecordSource)(IProfilerSession* self, ISC_INT64 statementId, unsigned cursorId, unsigned recSourceId, const char* accessPath, unsigned parentRecSourceId) throw(); void (CLOOP_CARG *onRequestStart)(IProfilerSession* self, IStatus* status, ISC_INT64 requestId, ISC_INT64 statementId, ISC_INT64 callerRequestId, ISC_TIMESTAMP_TZ timestamp) throw(); - void (CLOOP_CARG *onRequestFinish)(IProfilerSession* self, IStatus* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp) throw(); + void (CLOOP_CARG *onRequestFinish)(IProfilerSession* self, IStatus* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp, ISC_UINT64 runTime) throw(); void (CLOOP_CARG *beforePsqlLineColumn)(IProfilerSession* self, ISC_INT64 requestId, unsigned line, unsigned column) throw(); void (CLOOP_CARG *afterPsqlLineColumn)(IProfilerSession* self, ISC_INT64 requestId, unsigned line, unsigned column, ISC_UINT64 runTime) throw(); void (CLOOP_CARG *beforeRecordSourceOpen)(IProfilerSession* self, ISC_INT64 requestId, unsigned cursorId, unsigned recSourceId) throw(); @@ -6771,10 +6771,10 @@ namespace Firebird StatusType::checkException(status); } - template void onRequestFinish(StatusType* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp) + template void onRequestFinish(StatusType* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp, ISC_UINT64 runTime) { StatusType::clearException(status); - static_cast(this->cloopVTable)->onRequestFinish(this, status, requestId, timestamp); + static_cast(this->cloopVTable)->onRequestFinish(this, status, requestId, timestamp, runTime); StatusType::checkException(status); } @@ -20204,13 +20204,13 @@ namespace Firebird } } - static void CLOOP_CARG clooponRequestFinishDispatcher(IProfilerSession* self, IStatus* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp) throw() + static void CLOOP_CARG clooponRequestFinishDispatcher(IProfilerSession* self, IStatus* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp, ISC_UINT64 runTime) throw() { StatusType status2(status); try { - static_cast(self)->Name::onRequestFinish(&status2, requestId, timestamp); + static_cast(self)->Name::onRequestFinish(&status2, requestId, timestamp, runTime); } catch (...) { @@ -20323,7 +20323,7 @@ namespace Firebird virtual void defineStatement(StatusType* status, ISC_INT64 statementId, ISC_INT64 parentStatementId, const char* type, const char* packageName, const char* routineName, const char* sqlText) = 0; virtual void defineRecordSource(ISC_INT64 statementId, unsigned cursorId, unsigned recSourceId, const char* accessPath, unsigned parentRecSourceId) = 0; virtual void onRequestStart(StatusType* status, ISC_INT64 requestId, ISC_INT64 statementId, ISC_INT64 callerRequestId, ISC_TIMESTAMP_TZ timestamp) = 0; - virtual void onRequestFinish(StatusType* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp) = 0; + virtual void onRequestFinish(StatusType* status, ISC_INT64 requestId, ISC_TIMESTAMP_TZ timestamp, ISC_UINT64 runTime) = 0; virtual void beforePsqlLineColumn(ISC_INT64 requestId, unsigned line, unsigned column) = 0; virtual void afterPsqlLineColumn(ISC_INT64 requestId, unsigned line, unsigned column, ISC_UINT64 runTime) = 0; virtual void beforeRecordSourceOpen(ISC_INT64 requestId, unsigned cursorId, unsigned recSourceId) = 0; diff --git a/src/include/gen/Firebird.pas b/src/include/gen/Firebird.pas index 53ede42193..ae8bf34301 100644 --- a/src/include/gen/Firebird.pas +++ b/src/include/gen/Firebird.pas @@ -724,7 +724,7 @@ type IProfilerSession_defineStatementPtr = procedure(this: IProfilerSession; status: IStatus; statementId: Int64; parentStatementId: Int64; type_: PAnsiChar; packageName: PAnsiChar; routineName: PAnsiChar; sqlText: PAnsiChar); cdecl; IProfilerSession_defineRecordSourcePtr = procedure(this: IProfilerSession; statementId: Int64; cursorId: Cardinal; recSourceId: Cardinal; accessPath: PAnsiChar; parentRecSourceId: Cardinal); cdecl; IProfilerSession_onRequestStartPtr = procedure(this: IProfilerSession; status: IStatus; requestId: Int64; statementId: Int64; callerRequestId: Int64; timestamp: ISC_TIMESTAMP_TZ); cdecl; - IProfilerSession_onRequestFinishPtr = procedure(this: IProfilerSession; status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ); cdecl; + IProfilerSession_onRequestFinishPtr = procedure(this: IProfilerSession; status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ; runTime: QWord); cdecl; IProfilerSession_beforePsqlLineColumnPtr = procedure(this: IProfilerSession; requestId: Int64; line: Cardinal; column: Cardinal); cdecl; IProfilerSession_afterPsqlLineColumnPtr = procedure(this: IProfilerSession; requestId: Int64; line: Cardinal; column: Cardinal; runTime: QWord); cdecl; IProfilerSession_beforeRecordSourceOpenPtr = procedure(this: IProfilerSession; requestId: Int64; cursorId: Cardinal; recSourceId: Cardinal); cdecl; @@ -3821,7 +3821,7 @@ type procedure defineStatement(status: IStatus; statementId: Int64; parentStatementId: Int64; type_: PAnsiChar; packageName: PAnsiChar; routineName: PAnsiChar; sqlText: PAnsiChar); procedure defineRecordSource(statementId: Int64; cursorId: Cardinal; recSourceId: Cardinal; accessPath: PAnsiChar; parentRecSourceId: Cardinal); procedure onRequestStart(status: IStatus; requestId: Int64; statementId: Int64; callerRequestId: Int64; timestamp: ISC_TIMESTAMP_TZ); - procedure onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ); + procedure onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ; runTime: QWord); procedure beforePsqlLineColumn(requestId: Int64; line: Cardinal; column: Cardinal); procedure afterPsqlLineColumn(requestId: Int64; line: Cardinal; column: Cardinal; runTime: QWord); procedure beforeRecordSourceOpen(requestId: Int64; cursorId: Cardinal; recSourceId: Cardinal); @@ -3841,7 +3841,7 @@ type procedure defineStatement(status: IStatus; statementId: Int64; parentStatementId: Int64; type_: PAnsiChar; packageName: PAnsiChar; routineName: PAnsiChar; sqlText: PAnsiChar); virtual; abstract; procedure defineRecordSource(statementId: Int64; cursorId: Cardinal; recSourceId: Cardinal; accessPath: PAnsiChar; parentRecSourceId: Cardinal); virtual; abstract; procedure onRequestStart(status: IStatus; requestId: Int64; statementId: Int64; callerRequestId: Int64; timestamp: ISC_TIMESTAMP_TZ); virtual; abstract; - procedure onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ); virtual; abstract; + procedure onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ; runTime: QWord); virtual; abstract; procedure beforePsqlLineColumn(requestId: Int64; line: Cardinal; column: Cardinal); virtual; abstract; procedure afterPsqlLineColumn(requestId: Int64; line: Cardinal; column: Cardinal; runTime: QWord); virtual; abstract; procedure beforeRecordSourceOpen(requestId: Int64; cursorId: Cardinal; recSourceId: Cardinal); virtual; abstract; @@ -9002,9 +9002,9 @@ begin FbException.checkException(status); end; -procedure IProfilerSession.onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ); +procedure IProfilerSession.onRequestFinish(status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ; runTime: QWord); begin - ProfilerSessionVTable(vTable).onRequestFinish(Self, status, requestId, timestamp); + ProfilerSessionVTable(vTable).onRequestFinish(Self, status, requestId, timestamp, runTime); FbException.checkException(status); end; @@ -15683,10 +15683,10 @@ begin end end; -procedure IProfilerSessionImpl_onRequestFinishDispatcher(this: IProfilerSession; status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ); cdecl; +procedure IProfilerSessionImpl_onRequestFinishDispatcher(this: IProfilerSession; status: IStatus; requestId: Int64; timestamp: ISC_TIMESTAMP_TZ; runTime: QWord); cdecl; begin try - IProfilerSessionImpl(this).onRequestFinish(status, requestId, timestamp); + IProfilerSessionImpl(this).onRequestFinish(status, requestId, timestamp, runTime); except on e: Exception do FbException.catchException(status, e); end diff --git a/src/jrd/ProfilerManager.cpp b/src/jrd/ProfilerManager.cpp index ff2c352015..5121926134 100644 --- a/src/jrd/ProfilerManager.cpp +++ b/src/jrd/ProfilerManager.cpp @@ -510,14 +510,14 @@ void ProfilerManager::prepareRecSource(thread_db* tdbb, jrd_req* request, const } } -void ProfilerManager::onRequestFinish(jrd_req* request) +void ProfilerManager::onRequestFinish(jrd_req* request, FB_UINT64 runTime) { if (const auto profileRequestId = getRequest(request, 0)) { const auto timestamp = TimeZoneUtil::getCurrentTimeStamp(request->req_attachment->att_current_timezone); LogLocalStatus status("Profiler onRequestFinish"); - currentSession->pluginSession->onRequestFinish(&status, profileRequestId, timestamp); + currentSession->pluginSession->onRequestFinish(&status, profileRequestId, timestamp, runTime); currentSession->requests.findAndRemove(profileRequestId); } diff --git a/src/jrd/ProfilerManager.h b/src/jrd/ProfilerManager.h index ec73c36e1c..00c51930e4 100644 --- a/src/jrd/ProfilerManager.h +++ b/src/jrd/ProfilerManager.h @@ -103,7 +103,7 @@ public: const Firebird::PathName& pluginName, const Firebird::string& description, const Firebird::string& options); void prepareRecSource(thread_db* tdbb, jrd_req* request, const RecordSource* rsb); - void onRequestFinish(jrd_req* request); + void onRequestFinish(jrd_req* request, FB_UINT64 runTime); void beforePsqlLineColumn(jrd_req* request, ULONG line, ULONG column); void afterPsqlLineColumn(jrd_req* request, ULONG line, ULONG column, FB_UINT64 runTime); void beforeRecordSourceOpen(jrd_req* request, const RecordSource* rsb); diff --git a/src/jrd/exe.cpp b/src/jrd/exe.cpp index 596da65c18..a0648942bb 100644 --- a/src/jrd/exe.cpp +++ b/src/jrd/exe.cpp @@ -910,6 +910,8 @@ void EXE_start(thread_db* tdbb, jrd_req* request, jrd_tra* transaction) request->req_records_affected.clear(); + request->req_profiler_time = 0; + // Store request start time for timestamp work TimeZoneUtil::validateGmtTimeStamp(request->req_gmt_timestamp); @@ -1003,7 +1005,7 @@ void EXE_unwind(thread_db* tdbb, jrd_req* request) const auto attachment = request->req_attachment; if (attachment->isProfilerActive() && !request->hasInternalStatement()) - attachment->getProfilerManager(tdbb)->onRequestFinish(request); + attachment->getProfilerManager(tdbb)->onRequestFinish(request, request->req_profiler_time); } request->req_sorts.unlinkAll(); @@ -1359,7 +1361,8 @@ const StmtNode* EXE_looper(thread_db* tdbb, jrd_req* request, const StmtNode* no // Execute stuff until we drop - SINT64 lastPerfCounter = fb_utils::query_performance_counter(); + SINT64 initialPerfCounter = fb_utils::query_performance_counter(); + SINT64 lastPerfCounter = initialPerfCounter; const StmtNode* profileNode = nullptr; while (node && !(request->req_flags & req_stall)) @@ -1444,13 +1447,18 @@ const StmtNode* EXE_looper(thread_db* tdbb, jrd_req* request, const StmtNode* no } } // while() - if (attachment->isProfilerActive() && !request->hasInternalStatement() && profileNode) + if (attachment->isProfilerActive() && !request->hasInternalStatement()) { const SINT64 currentPerfCounter = fb_utils::query_performance_counter(); - attachment->getProfilerManager(tdbb)->afterPsqlLineColumn(request, - profileNode->line, profileNode->column, - currentPerfCounter - lastPerfCounter); + if (profileNode) + { + attachment->getProfilerManager(tdbb)->afterPsqlLineColumn(request, + profileNode->line, profileNode->column, + currentPerfCounter - lastPerfCounter); + } + + request->req_profiler_time += currentPerfCounter - initialPerfCounter; } request->adjustCallerStats(); @@ -1477,6 +1485,9 @@ const StmtNode* EXE_looper(thread_db* tdbb, jrd_req* request, const StmtNode* no request->req_flags &= ~(req_active | req_reserved); request->req_gmt_timestamp.invalidate(); release_blobs(tdbb, request); + + if (attachment->isProfilerActive() && !request->hasInternalStatement()) + attachment->getProfilerManager(tdbb)->onRequestFinish(request, request->req_profiler_time); } request->req_next = node; diff --git a/src/jrd/req.h b/src/jrd/req.h index f6d68a601c..54b3c358d6 100644 --- a/src/jrd/req.h +++ b/src/jrd/req.h @@ -269,6 +269,7 @@ public: RuntimeStatistics req_stats; RuntimeStatistics req_base_stats; AffectedRows req_records_affected; // records affected by the last statement + FB_UINT64 req_profiler_time; // profiler time const StmtNode* req_next; // next node for execution EDS::Statement* req_ext_stmt; // head of list of active dynamic statements diff --git a/src/plugins/profiler/Profiler.cpp b/src/plugins/profiler/Profiler.cpp index 597ed41930..620082fb74 100644 --- a/src/plugins/profiler/Profiler.cpp +++ b/src/plugins/profiler/Profiler.cpp @@ -119,6 +119,7 @@ struct Request SINT64 callerRequestId; ISC_TIMESTAMP_TZ startTimestamp; Nullable finishTimestamp; + Nullable totalTime; NonPooledMap recordSourcesStats{defaultPool()}; NonPooledMap psqlStats{defaultPool()}; }; @@ -164,7 +165,8 @@ public: void onRequestStart(ThrowStatusExceptionWrapper* status, SINT64 requestId, SINT64 statementId, SINT64 callerRequestId, ISC_TIMESTAMP_TZ timestamp) override; - void onRequestFinish(ThrowStatusExceptionWrapper* status, SINT64 requestId, ISC_TIMESTAMP_TZ timestamp) override; + void onRequestFinish(ThrowStatusExceptionWrapper* status, SINT64 requestId, + ISC_TIMESTAMP_TZ timestamp, FB_UINT64 runTime) override; void beforePsqlLineColumn(SINT64 requestId, unsigned line, unsigned column) override { @@ -391,8 +393,8 @@ void ProfilerPlugin::flush(ThrowStatusExceptionWrapper* status) constexpr auto requestSql = R"""( update or insert into plg$prof_requests - (profile_id, request_id, statement_id, caller_request_id, start_timestamp, finish_timestamp) - values (?, ?, ?, ?, ?, ?) + (profile_id, request_id, statement_id, caller_request_id, start_timestamp, finish_timestamp, total_time) + values (?, ?, ?, ?, ?, ?, ?) matching (profile_id, request_id) )"""; @@ -403,6 +405,7 @@ void ProfilerPlugin::flush(ThrowStatusExceptionWrapper* status) (FB_BIGINT, callerRequestId) (FB_TIMESTAMP_TZ, startTimestamp) (FB_TIMESTAMP_TZ, finishTimestamp) + (FB_BIGINT, totalTime) ) requestMessage(status, MasterInterfacePtr()); requestMessage.clear(); @@ -732,6 +735,9 @@ void ProfilerPlugin::flush(ThrowStatusExceptionWrapper* status) requestMessage->finishTimestampNull = profileRequest.finishTimestamp.isUnknown(); requestMessage->finishTimestamp = profileRequest.finishTimestamp.value; + requestMessage->totalTimeNull = profileRequest.totalTime.isUnknown(); + requestMessage->totalTime = profileRequest.totalTime.value; + addBatch(requestBatch, requestBatchSize, requestMessage); if (profileRequest.finishTimestamp.isAssigned()) @@ -938,6 +944,7 @@ void ProfilerPlugin::createMetadata(ThrowStatusExceptionWrapper* status, RefPtr< caller_request_id bigint, start_timestamp timestamp with time zone not null, finish_timestamp timestamp with time zone, + total_time bigint, constraint plg$prof_requests_pk primary key (profile_id, request_id) using index plg$prof_requests_profile_request, @@ -1021,6 +1028,47 @@ void ProfilerPlugin::createMetadata(ThrowStatusExceptionWrapper* status, RefPtr< "grant select, update, insert, delete on table plg$prof_record_source_stats to plg$profiler", + R"""( + create view plg$prof_statement_stats_view + as + select req.profile_id, + req.statement_id, + sta.statement_type, + sta.package_name, + sta.routine_name, + sta.parent_statement_id, + sta_parent.statement_type parent_statement_type, + sta_parent.routine_name parent_routine_name, + (select sql_text + from plg$prof_statements + where profile_id = req.profile_id and + statement_id = coalesce(sta.parent_statement_id, req.statement_id) + ) sql_text, + count(*) counter, + min(req.total_time) min_time, + max(req.total_time) max_time, + sum(req.total_time) total_time, + sum(req.total_time) / count(*) avg_time + from plg$prof_requests req + join plg$prof_statements sta + on sta.profile_id = req.profile_id and + sta.statement_id = req.statement_id + left join plg$prof_statements sta_parent + on sta_parent.profile_id = sta.profile_id and + sta_parent.statement_id = sta.parent_statement_id + group by req.profile_id, + req.statement_id, + sta.statement_type, + sta.package_name, + sta.routine_name, + sta.parent_statement_id, + sta_parent.statement_type, + sta_parent.routine_name + order by sum(req.total_time) desc + )""", + + "grant select on table plg$prof_statement_stats_view to plg$profiler", + R"""( create view plg$prof_psql_stats_view as @@ -1283,12 +1331,14 @@ void Session::onRequestStart(ThrowStatusExceptionWrapper* status, SINT64 request request->startTimestamp = timestamp; } -void Session::onRequestFinish(ThrowStatusExceptionWrapper* status, SINT64 requestId, ISC_TIMESTAMP_TZ timestamp) +void Session::onRequestFinish(ThrowStatusExceptionWrapper* status, SINT64 requestId, + ISC_TIMESTAMP_TZ timestamp, FB_UINT64 runTime) { if (auto request = requests.get(requestId)) { request->dirty = true; request->finishTimestamp = timestamp; + request->totalTime = runTime; } }