From 7e64a2e361adcdbd2fce5ad76051a150b4de062d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?louiz=E2=80=99?= Date: Sun, 14 Jan 2018 21:46:49 +0100 Subject: Add a DEBUG_SQL_QUERIES to log info about the executed SQL queries fix #3324 --- src/biboumi.h.cmake | 2 ++ src/database/count_query.hpp | 3 +++ src/database/insert_query.hpp | 4 ++++ src/database/postgresql_engine.cpp | 6 ++++++ src/database/query.hpp | 29 +++++++++++++++++++++++++++++ src/database/select_query.hpp | 4 ++++ src/database/sqlite3_engine.cpp | 7 +++++++ src/database/update_query.hpp | 4 ++++ src/utils/scopetimer.hpp | 17 +++++++++++++++++ 9 files changed, 76 insertions(+) create mode 100644 src/utils/scopetimer.hpp (limited to 'src') diff --git a/src/biboumi.h.cmake b/src/biboumi.h.cmake index 5bc1004..fa99cd4 100644 --- a/src/biboumi.h.cmake +++ b/src/biboumi.h.cmake @@ -12,3 +12,5 @@ #cmakedefine PROJECT_NAME "${PROJECT_NAME}" #cmakedefine HAS_GET_TIME #cmakedefine HAS_PUT_TIME +#cmakedefine DEBUG_SQL_QUERIES + diff --git a/src/database/count_query.hpp b/src/database/count_query.hpp index e8d24ef..118ce44 100644 --- a/src/database/count_query.hpp +++ b/src/database/count_query.hpp @@ -16,6 +16,9 @@ struct CountQuery: public Query int64_t execute(DatabaseEngine& db) { +#ifdef DEBUG_SQL_QUERIES + const auto timer = this->log_and_time(); +#endif auto statement = db.prepare(this->body); int64_t res = 0; if (statement->step() != StepResult::Error) diff --git a/src/database/insert_query.hpp b/src/database/insert_query.hpp index 17cc245..9726424 100644 --- a/src/database/insert_query.hpp +++ b/src/database/insert_query.hpp @@ -39,6 +39,10 @@ struct InsertQuery: public Query template void execute(DatabaseEngine& db, std::tuple& columns) { +#ifdef DEBUG_SQL_QUERIES + const auto timer = this->log_and_time(); +#endif + auto statement = db.prepare(this->body); this->bind_param(columns, *statement); diff --git a/src/database/postgresql_engine.cpp b/src/database/postgresql_engine.cpp index 150ca42..984a959 100644 --- a/src/database/postgresql_engine.cpp +++ b/src/database/postgresql_engine.cpp @@ -3,6 +3,8 @@ #include +#include + #include #include @@ -51,6 +53,10 @@ std::set PostgresqlEngine::get_all_columns_from_table(const std::st std::tuple PostgresqlEngine::raw_exec(const std::string& query) { +#ifdef DEBUG_SQL_QUERIES + log_debug("SQL QUERY: ", query); + const auto timer = make_sql_timer(); +#endif PGresult* res = PQexec(this->conn, query.data()); auto sg = utils::make_scope_guard([res](){ PQclear(res); diff --git a/src/database/query.hpp b/src/database/query.hpp index 7f8aecb..547138f 100644 --- a/src/database/query.hpp +++ b/src/database/query.hpp @@ -1,5 +1,7 @@ #pragma once +#include + #include #include #include @@ -13,6 +15,20 @@ void actual_bind(Statement& statement, const std::string& value, int index); void actual_bind(Statement& statement, const std::size_t value, int index); void actual_bind(Statement& statement, const OptionalBool& value, int index); +#ifdef DEBUG_SQL_QUERIES +#include + +inline auto make_sql_timer() +{ + return make_scope_timer([](const std::chrono::steady_clock::duration& elapsed) + { + const auto seconds = std::chrono::duration_cast(elapsed); + const auto rest = elapsed - seconds; + log_debug("Query executed in ", seconds.count(), ".", rest.count(), "s."); + }); +} +#endif + struct Query { std::string body; @@ -22,6 +38,18 @@ struct Query Query(std::string str): body(std::move(str)) {} + +#ifdef DEBUG_SQL_QUERIES + auto log_and_time() + { + std::ostringstream os; + os << this->body << "; "; + for (const auto& param: this->params) + os << "'" << param << "' "; + log_debug("SQL QUERY: ", os.str()); + return make_sql_timer(); + } +#endif }; template @@ -58,3 +86,4 @@ operator<<(Query& query, const Integer& i) actual_add_param(query, i); return query; } + diff --git a/src/database/select_query.hpp b/src/database/select_query.hpp index af2ac1c..5a17f38 100644 --- a/src/database/select_query.hpp +++ b/src/database/select_query.hpp @@ -110,6 +110,10 @@ struct SelectQuery: public Query { std::vector> rows; +#ifdef DEBUG_SQL_QUERIES + const auto timer = this->log_and_time(); +#endif + auto statement = db.prepare(this->body); statement->bind(std::move(this->params)); diff --git a/src/database/sqlite3_engine.cpp b/src/database/sqlite3_engine.cpp index 92d514b..ae4a146 100644 --- a/src/database/sqlite3_engine.cpp +++ b/src/database/sqlite3_engine.cpp @@ -6,6 +6,8 @@ #include +#include + #include #include #include @@ -57,6 +59,11 @@ std::unique_ptr Sqlite3Engine::open(const std::string& filename) std::tuple Sqlite3Engine::raw_exec(const std::string& query) { +#ifdef DEBUG_SQL_QUERIES + log_debug("SQL QUERY: ", query); + const auto timer = make_sql_timer(); +#endif + char* error; const auto result = sqlite3_exec(db, query.data(), nullptr, nullptr, &error); if (result != SQLITE_OK) diff --git a/src/database/update_query.hpp b/src/database/update_query.hpp index 32befc0..a29ac3f 100644 --- a/src/database/update_query.hpp +++ b/src/database/update_query.hpp @@ -64,6 +64,10 @@ struct UpdateQuery: public Query template void execute(DatabaseEngine& db, const std::tuple& columns) { +#ifdef DEBUG_SQL_QUERIES + const auto timer = this->log_and_time(); +#endif + auto statement = db.prepare(this->body); this->bind_param(columns, *statement); this->bind_id(columns, *statement); diff --git a/src/utils/scopetimer.hpp b/src/utils/scopetimer.hpp new file mode 100644 index 0000000..7d3db9b --- /dev/null +++ b/src/utils/scopetimer.hpp @@ -0,0 +1,17 @@ +#include + +#include + +#include + +template +auto make_scope_timer(Callback cb) +{ + const auto start_time = std::chrono::steady_clock::now(); + return utils::make_scope_guard([start_time, cb = std::move(cb)]() + { + const auto now = std::chrono::steady_clock::now(); + const auto elapsed = now - start_time; + cb(elapsed); + }); +} -- cgit v1.2.3