mirror of https://github.com/sysown/proxysql
Signed-off-by: René Cannaò <rene@proxysql.com>v3.0-tsdb-feature
René Cannaò
4 days ago
committed by
GitHub
commit
9c6945fae8
@ -0,0 +1,210 @@
|
||||
# PostgreSQL Advanced Query Logging Architecture
|
||||
|
||||
## Document Status
|
||||
- Status: Implemented (as-built)
|
||||
- Scope: PostgreSQL advanced events logging parity with MySQL, including buffer, SQLite sinks, dump commands, scheduler sync, and metrics
|
||||
- Branch: `v3.0_pgsql_advanced_logging`
|
||||
|
||||
## 1. Objective and Delivered Outcome
|
||||
The PostgreSQL logging pipeline now supports advanced query events logging with the same operational model already used by MySQL:
|
||||
- query event capture at request completion
|
||||
- in-memory circular buffering
|
||||
- manual dump from buffer to `stats` and/or `stats_history`
|
||||
- optional periodic auto-dump to disk
|
||||
- logger metrics in `stats_pgsql_global` and Prometheus
|
||||
|
||||
This implementation is additive. Existing PostgreSQL file-based events log and audit log behavior remains available.
|
||||
|
||||
## 2. As-Built Runtime Architecture
|
||||
|
||||
### 2.1 Capture path
|
||||
1. PostgreSQL sessions call query logging at request completion.
|
||||
2. `PgSQL_Logger::log_request()` builds a `PgSQL_Event` from session/backend state.
|
||||
3. If file logging is enabled, the event is written to events log file.
|
||||
4. If `pgsql-eventslog_buffer_history_size > 0`, the event is deep-copied and inserted into the PostgreSQL events circular buffer.
|
||||
|
||||
Implemented in:
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
- `include/PgSQL_Logger.hpp`
|
||||
|
||||
### 2.2 Buffering model
|
||||
A dedicated `PgSQL_Logger_CircularBuffer` provides:
|
||||
- thread-safe insertion/drain using mutex
|
||||
- bounded size via runtime variable
|
||||
- event drop accounting when the buffer is full or resized smaller
|
||||
|
||||
Runtime resizing is wired in PostgreSQL thread variable refresh:
|
||||
- `PgSQL_Thread::refresh_variables()` applies `eventslog_buffer_history_size` changes to the live circular buffer.
|
||||
|
||||
Implemented in:
|
||||
- `include/PgSQL_Logger.hpp`
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
- `lib/PgSQL_Thread.cpp`
|
||||
|
||||
### 2.3 Drain and persistence pipeline
|
||||
`PgSQL_Logger::processEvents(SQLite3DB* statsdb, SQLite3DB* statsdb_disk)` drains the buffer and persists events to:
|
||||
- memory table: `stats_pgsql_query_events` when `statsdb != nullptr`
|
||||
- disk table: `history_pgsql_query_events` when `statsdb_disk != nullptr`
|
||||
|
||||
Behavior:
|
||||
- batched SQLite inserts with prepared statements
|
||||
- in-memory retention bound by `pgsql-eventslog_table_memory_size`
|
||||
- query digest serialized as hex text (`0x...`), matching MySQL table style
|
||||
- `sqlstate` and textual `error` persisted for failed queries
|
||||
|
||||
Implemented in:
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
|
||||
## 3. Data Model
|
||||
|
||||
### 3.1 Memory table
|
||||
`stats.stats_pgsql_query_events`
|
||||
|
||||
Columns:
|
||||
- `id`
|
||||
- `thread_id`
|
||||
- `username`
|
||||
- `database`
|
||||
- `start_time`
|
||||
- `end_time`
|
||||
- `query_digest`
|
||||
- `query`
|
||||
- `server`
|
||||
- `client`
|
||||
- `event_type`
|
||||
- `hid`
|
||||
- `extra_info`
|
||||
- `affected_rows`
|
||||
- `rows_sent`
|
||||
- `client_stmt_name`
|
||||
- `sqlstate`
|
||||
- `error`
|
||||
|
||||
Implemented in:
|
||||
- `include/ProxySQL_Admin_Tables_Definitions.h`
|
||||
- `lib/Admin_Bootstrap.cpp`
|
||||
|
||||
### 3.2 Disk history table
|
||||
`stats_history.history_pgsql_query_events`
|
||||
|
||||
Columns match `stats_pgsql_query_events`.
|
||||
|
||||
Indexes:
|
||||
- `idx_history_pgsql_query_events_start_time` on `start_time`
|
||||
- `idx_history_pgsql_query_events_query_digest` on `query_digest`
|
||||
|
||||
Implemented in:
|
||||
- `include/ProxySQL_Statistics.hpp`
|
||||
- `lib/ProxySQL_Statistics.cpp`
|
||||
|
||||
## 4. Admin Interface and Control Surface
|
||||
|
||||
### 4.1 Dump commands
|
||||
PostgreSQL-specific dump commands are now available:
|
||||
- `DUMP PGSQL EVENTSLOG FROM BUFFER TO MEMORY`
|
||||
- `DUMP PGSQL EVENTSLOG FROM BUFFER TO DISK`
|
||||
- `DUMP PGSQL EVENTSLOG FROM BUFFER TO BOTH`
|
||||
|
||||
Command handling executes `GloPgSQL_Logger->processEvents(...)` with the selected sink targets.
|
||||
|
||||
These commands are exposed by the shared Admin module and are available from both Admin protocol endpoints:
|
||||
- MySQL protocol on port `6032`
|
||||
- PostgreSQL protocol on port `6132`
|
||||
|
||||
Implemented in:
|
||||
- `lib/Admin_Handler.cpp`
|
||||
|
||||
### 4.2 Runtime/config variables
|
||||
PostgreSQL thread variables used by advanced logging:
|
||||
- `pgsql-eventslog_buffer_history_size`
|
||||
- `pgsql-eventslog_table_memory_size`
|
||||
- `pgsql-eventslog_buffer_max_query_length`
|
||||
|
||||
Admin scheduling variable:
|
||||
- `admin-stats_pgsql_eventslog_sync_buffer_to_disk`
|
||||
|
||||
Implemented in:
|
||||
- `include/PgSQL_Thread.h`
|
||||
- `include/proxysql_structs.h`
|
||||
- `include/proxysql_admin.h`
|
||||
- `lib/ProxySQL_Admin.cpp`
|
||||
|
||||
## 5. Scheduler Integration
|
||||
|
||||
### 5.1 PostgreSQL auto-dump to disk
|
||||
Admin main loop now periodically flushes PostgreSQL buffered events to `history_pgsql_query_events` when:
|
||||
- `stats_pgsql_eventslog_sync_buffer_to_disk > 0`
|
||||
- timer interval is elapsed
|
||||
|
||||
### 5.2 MySQL symmetry fix
|
||||
The same scheduler loop now also invokes MySQL buffered events dump to disk based on `stats_mysql_eventslog_sync_buffer_to_disk`, ensuring symmetric behavior across both protocols.
|
||||
|
||||
Implemented in:
|
||||
- `lib/ProxySQL_Admin.cpp`
|
||||
|
||||
## 6. Metrics Architecture
|
||||
|
||||
### 6.1 Logger internal metrics
|
||||
PostgreSQL logger tracks:
|
||||
- memory/disk copy counts
|
||||
- total copy time (memory/disk)
|
||||
- get-all-events calls/time/count
|
||||
- total events copied (memory/disk)
|
||||
- circular buffer added/dropped totals
|
||||
- circular buffer current size
|
||||
|
||||
Implemented in:
|
||||
- `include/PgSQL_Logger.hpp`
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
|
||||
### 6.2 Stats table exposure
|
||||
Metrics are exported to `stats_pgsql_global` with `PgSQL_Logger_` prefix.
|
||||
|
||||
Implemented in:
|
||||
- `lib/ProxySQL_Admin_Stats.cpp`
|
||||
|
||||
### 6.3 Prometheus exposure
|
||||
Prometheus metric family `proxysql_pgsql_logger_*` is exposed through the serial metrics updater path.
|
||||
|
||||
Implemented in:
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
- `lib/ProxySQL_Admin.cpp`
|
||||
|
||||
## 7. Compatibility and Semantics
|
||||
- Existing `DUMP EVENTSLOG ...` remains MySQL behavior for compatibility.
|
||||
- New PostgreSQL syntax is explicit: `DUMP PGSQL EVENTSLOG ...`.
|
||||
- PostgreSQL event error fields use `sqlstate + error` (textual message).
|
||||
- PostgreSQL event table uses `database` column naming.
|
||||
|
||||
## 8. Code Touchpoint Summary
|
||||
- Logger core:
|
||||
- `include/PgSQL_Logger.hpp`
|
||||
- `lib/PgSQL_Logger.cpp`
|
||||
- Thread/runtime integration:
|
||||
- `lib/PgSQL_Thread.cpp`
|
||||
- Admin commands and scheduler:
|
||||
- `lib/Admin_Handler.cpp`
|
||||
- `lib/ProxySQL_Admin.cpp`
|
||||
- Table definitions/bootstrap:
|
||||
- `include/ProxySQL_Admin_Tables_Definitions.h`
|
||||
- `include/ProxySQL_Statistics.hpp`
|
||||
- `lib/Admin_Bootstrap.cpp`
|
||||
- `lib/ProxySQL_Statistics.cpp`
|
||||
- Stats/Prometheus metrics:
|
||||
- `lib/ProxySQL_Admin_Stats.cpp`
|
||||
|
||||
## 9. Validation and Acceptance Mapping
|
||||
Implemented acceptance validation via TAP test:
|
||||
- `test/tap/tests/pgsql_query_logging_memory-t.cpp`
|
||||
- `test/tap/tests/pgsql_query_logging_autodump-t.cpp`
|
||||
|
||||
Coverage:
|
||||
- table schema shape validation (`stats_pgsql_query_events`, `history_pgsql_query_events`)
|
||||
- buffer dump command execution
|
||||
- success/error event accounting in memory and history tables
|
||||
- `sqlstate` capture for representative PostgreSQL errors
|
||||
- non-empty textual `error` capture for error rows
|
||||
- scheduler-driven periodic dump to `history_pgsql_query_events` via `admin-stats_pgsql_eventslog_sync_buffer_to_disk`
|
||||
|
||||
TAP group registration:
|
||||
- `test/tap/groups/groups.json` (`pgsql_query_logging_memory-t`, `pgsql_query_logging_autodump-t`)
|
||||
@ -0,0 +1,194 @@
|
||||
/**
|
||||
* @file pgsql_query_logging_autodump-t.cpp
|
||||
* @brief TAP test for PostgreSQL eventslog automatic buffer-to-disk sync.
|
||||
*/
|
||||
|
||||
#include <memory>
|
||||
#include <sstream>
|
||||
#include <string>
|
||||
#include <unistd.h>
|
||||
|
||||
#include "libpq-fe.h"
|
||||
|
||||
#include "command_line.h"
|
||||
#include "tap.h"
|
||||
#include "utils.h"
|
||||
|
||||
using PGConnPtr = std::unique_ptr<PGconn, decltype(&PQfinish)>;
|
||||
using std::string;
|
||||
|
||||
/**
|
||||
* @brief Creates a PostgreSQL connection from a libpq connection string.
|
||||
*/
|
||||
PGConnPtr create_connection(const std::string& conn_info) {
|
||||
PGconn* conn = PQconnectdb(conn_info.c_str());
|
||||
if (conn == nullptr || PQstatus(conn) != CONNECTION_OK) {
|
||||
if (conn) {
|
||||
diag("Connection failed: %s", PQerrorMessage(conn));
|
||||
PQfinish(conn);
|
||||
} else {
|
||||
diag("Connection failed: PQconnectdb returned nullptr");
|
||||
}
|
||||
return PGConnPtr(nullptr, &PQfinish);
|
||||
}
|
||||
return PGConnPtr(conn, &PQfinish);
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Executes a query and expects command-ok or tuples-ok.
|
||||
*/
|
||||
bool exec_ok(PGconn* conn, const std::string& query) {
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("Query failed (null result): %s", query.c_str());
|
||||
return false;
|
||||
}
|
||||
ExecStatusType status = PQresultStatus(res);
|
||||
bool ok_status = (status == PGRES_COMMAND_OK || status == PGRES_TUPLES_OK);
|
||||
if (!ok_status) {
|
||||
diag("Query failed: %s", query.c_str());
|
||||
diag("Error: %s", PQresultErrorMessage(res));
|
||||
}
|
||||
PQclear(res);
|
||||
return ok_status;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Executes scalar query returning one integer result.
|
||||
*/
|
||||
bool query_one_int(PGconn* conn, const std::string& query, long long& value) {
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("Scalar query failed (null result): %s", query.c_str());
|
||||
return false;
|
||||
}
|
||||
if (PQresultStatus(res) != PGRES_TUPLES_OK || PQntuples(res) != 1 || PQnfields(res) != 1) {
|
||||
diag("Scalar query returned unexpected shape: %s", query.c_str());
|
||||
diag("Error: %s", PQresultErrorMessage(res));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
value = atoll(PQgetvalue(res, 0, 0));
|
||||
PQclear(res);
|
||||
return true;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Waits until row count in history table has increased by at least delta.
|
||||
*/
|
||||
bool wait_for_history_delta(PGconn* admin_conn, long long baseline, long long delta, int timeout_seconds) {
|
||||
for (int i = 0; i < timeout_seconds; ++i) {
|
||||
long long count = 0;
|
||||
if (!query_one_int(admin_conn, "SELECT COUNT(*) FROM history_pgsql_query_events", count)) {
|
||||
return false;
|
||||
}
|
||||
if (count - baseline >= delta) {
|
||||
return true;
|
||||
}
|
||||
sleep(1);
|
||||
}
|
||||
return false;
|
||||
}
|
||||
|
||||
int main() {
|
||||
CommandLine cl;
|
||||
if (cl.getEnv()) {
|
||||
diag("Failed to get the required environmental variables.");
|
||||
return -1;
|
||||
}
|
||||
|
||||
plan(8);
|
||||
|
||||
std::stringstream admin_ss;
|
||||
admin_ss << "host=" << cl.pgsql_admin_host
|
||||
<< " port=" << cl.pgsql_admin_port
|
||||
<< " user=" << cl.admin_username
|
||||
<< " password=" << cl.admin_password
|
||||
<< " dbname=postgres";
|
||||
PGConnPtr admin_conn = create_connection(admin_ss.str());
|
||||
ok(admin_conn != nullptr, "Connected to PostgreSQL admin interface");
|
||||
if (!admin_conn) {
|
||||
return exit_status();
|
||||
}
|
||||
|
||||
std::stringstream backend_ss;
|
||||
backend_ss << "host=" << cl.pgsql_host
|
||||
<< " port=" << cl.pgsql_port
|
||||
<< " user=" << cl.pgsql_username
|
||||
<< " password=" << cl.pgsql_password;
|
||||
PGConnPtr backend_conn = create_connection(backend_ss.str());
|
||||
ok(backend_conn != nullptr, "Connected to PostgreSQL frontend interface");
|
||||
if (!backend_conn) {
|
||||
return exit_status();
|
||||
}
|
||||
|
||||
bool setup_ok = true;
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "SET pgsql-eventslog_buffer_history_size=1000000");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "SET pgsql-eventslog_default_log=1");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "SET admin-stats_pgsql_eventslog_sync_buffer_to_disk=1");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "LOAD PGSQL VARIABLES TO RUNTIME");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "LOAD ADMIN VARIABLES TO RUNTIME");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "DUMP PGSQL EVENTSLOG FROM BUFFER TO DISK");
|
||||
setup_ok = setup_ok && exec_ok(admin_conn.get(), "DELETE FROM history_pgsql_query_events");
|
||||
ok(setup_ok, "Configured PGSQL eventslog buffer and auto-dump scheduler");
|
||||
if (!setup_ok) {
|
||||
return exit_status();
|
||||
}
|
||||
|
||||
long long baseline = 0;
|
||||
bool baseline_ok = query_one_int(admin_conn.get(), "SELECT COUNT(*) FROM history_pgsql_query_events", baseline);
|
||||
ok(baseline_ok, "Collected baseline row count from history_pgsql_query_events");
|
||||
if (!baseline_ok) {
|
||||
return exit_status();
|
||||
}
|
||||
|
||||
const int num_queries = 30;
|
||||
bool run_queries_ok = true;
|
||||
for (int i = 0; i < num_queries; ++i) {
|
||||
PGresult* res = PQexec(backend_conn.get(), "SELECT 1");
|
||||
if (res == nullptr || PQresultStatus(res) != PGRES_TUPLES_OK) {
|
||||
run_queries_ok = false;
|
||||
if (res) {
|
||||
diag("Query failed during workload generation: %s", PQresultErrorMessage(res));
|
||||
} else {
|
||||
diag("Query failed during workload generation: null result");
|
||||
}
|
||||
if (res) PQclear(res);
|
||||
break;
|
||||
}
|
||||
PQclear(res);
|
||||
}
|
||||
ok(run_queries_ok, "Generated PostgreSQL query workload");
|
||||
if (!run_queries_ok) {
|
||||
return exit_status();
|
||||
}
|
||||
|
||||
bool auto_dump_ok = wait_for_history_delta(admin_conn.get(), baseline, num_queries, 20);
|
||||
ok(auto_dump_ok, "Automatic scheduler dumped buffered PGSQL events to disk");
|
||||
|
||||
long long success_rows = -1;
|
||||
bool success_rows_ok = query_one_int(
|
||||
admin_conn.get(),
|
||||
"SELECT COUNT(*) FROM history_pgsql_query_events WHERE sqlstate IS NULL",
|
||||
success_rows
|
||||
);
|
||||
if (!success_rows_ok || success_rows < num_queries) {
|
||||
diag(
|
||||
"Expected >= %d successful rows, got %lld (query_ok=%s)",
|
||||
num_queries,
|
||||
success_rows,
|
||||
success_rows_ok ? "true" : "false"
|
||||
);
|
||||
}
|
||||
ok(success_rows_ok && success_rows >= num_queries, "History table includes expected successful rows");
|
||||
|
||||
bool cleanup_ok = true;
|
||||
cleanup_ok = cleanup_ok && exec_ok(admin_conn.get(), "SET admin-stats_pgsql_eventslog_sync_buffer_to_disk=0");
|
||||
cleanup_ok = cleanup_ok && exec_ok(admin_conn.get(), "SET pgsql-eventslog_default_log=0");
|
||||
cleanup_ok = cleanup_ok && exec_ok(admin_conn.get(), "SET pgsql-eventslog_buffer_history_size=0");
|
||||
cleanup_ok = cleanup_ok && exec_ok(admin_conn.get(), "LOAD ADMIN VARIABLES TO RUNTIME");
|
||||
cleanup_ok = cleanup_ok && exec_ok(admin_conn.get(), "LOAD PGSQL VARIABLES TO RUNTIME");
|
||||
ok(cleanup_ok, "Cleanup completed and auto-dump scheduler disabled");
|
||||
|
||||
return exit_status();
|
||||
}
|
||||
@ -0,0 +1,320 @@
|
||||
/**
|
||||
* @file pgsql_query_logging_memory-t.cpp
|
||||
* @brief TAP test for PostgreSQL advanced query logging in memory and history tables.
|
||||
*/
|
||||
|
||||
#include <map>
|
||||
#include <memory>
|
||||
#include <sstream>
|
||||
#include <string>
|
||||
#include <vector>
|
||||
|
||||
#include "libpq-fe.h"
|
||||
|
||||
#include "command_line.h"
|
||||
#include "tap.h"
|
||||
#include "utils.h"
|
||||
|
||||
using PGConnPtr = std::unique_ptr<PGconn, decltype(&PQfinish)>;
|
||||
using std::string;
|
||||
|
||||
/**
|
||||
* @brief Opens a PostgreSQL connection using the supplied connection parameters.
|
||||
*/
|
||||
PGConnPtr create_connection(const std::string& conn_info) {
|
||||
PGconn* conn = PQconnectdb(conn_info.c_str());
|
||||
if (!conn || PQstatus(conn) != CONNECTION_OK) {
|
||||
if (conn) {
|
||||
diag("Connection failed: %s", PQerrorMessage(conn));
|
||||
PQfinish(conn);
|
||||
} else {
|
||||
diag("Connection failed: PQconnectdb returned nullptr");
|
||||
}
|
||||
return PGConnPtr(nullptr, &PQfinish);
|
||||
}
|
||||
return PGConnPtr(conn, &PQfinish);
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Executes a statement and expects either command-ok or tuples-ok result.
|
||||
*/
|
||||
bool exec_ok(PGconn* conn, const std::string& query) {
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("Query failed (null result): %s", query.c_str());
|
||||
return false;
|
||||
}
|
||||
ExecStatusType st = PQresultStatus(res);
|
||||
bool ok_status = (st == PGRES_COMMAND_OK || st == PGRES_TUPLES_OK);
|
||||
if (!ok_status) {
|
||||
diag("Query failed: %s", query.c_str());
|
||||
diag("Error: %s", PQresultErrorMessage(res));
|
||||
}
|
||||
PQclear(res);
|
||||
return ok_status;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Executes a scalar query returning one integer value.
|
||||
*/
|
||||
bool query_one_int(PGconn* conn, const std::string& query, long long& value) {
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("Scalar query returned null result: %s", query.c_str());
|
||||
return false;
|
||||
}
|
||||
if (PQresultStatus(res) != PGRES_TUPLES_OK || PQntuples(res) != 1 || PQnfields(res) != 1) {
|
||||
diag("Scalar query returned unexpected shape: %s", query.c_str());
|
||||
diag("Error: %s", PQresultErrorMessage(res));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
value = atoll(PQgetvalue(res, 0, 0));
|
||||
PQclear(res);
|
||||
return true;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Validates field names for a query result.
|
||||
*/
|
||||
bool check_columns(PGconn* conn, const std::string& query, const std::vector<std::string>& expected_columns) {
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("Column check query returned null result: %s", query.c_str());
|
||||
return false;
|
||||
}
|
||||
if (PQresultStatus(res) != PGRES_TUPLES_OK) {
|
||||
diag("Column check query failed: %s", query.c_str());
|
||||
diag("Error: %s", PQresultErrorMessage(res));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
|
||||
bool same_count = (PQnfields(res) == static_cast<int>(expected_columns.size()));
|
||||
if (!same_count) {
|
||||
diag("Column count mismatch for query: %s", query.c_str());
|
||||
diag("Expected: %zu, got: %d", expected_columns.size(), PQnfields(res));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
|
||||
for (int i = 0; i < PQnfields(res); ++i) {
|
||||
const char* actual = PQfname(res, i);
|
||||
if (actual == nullptr || expected_columns[i] != actual) {
|
||||
diag("Column mismatch at position %d for query: %s", i, query.c_str());
|
||||
diag("Expected: %s, got: %s", expected_columns[i].c_str(), (actual ? actual : "<null>"));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
}
|
||||
|
||||
PQclear(res);
|
||||
return true;
|
||||
}
|
||||
|
||||
/**
|
||||
* @brief Reads SQLSTATE counts from the target events table.
|
||||
*/
|
||||
bool get_sqlstate_counts(PGconn* conn, const std::string& table_name, std::map<std::string, int>& counts) {
|
||||
const std::string query =
|
||||
"SELECT COALESCE(sqlstate, ''), COUNT(*) "
|
||||
"FROM " + table_name + " "
|
||||
"GROUP BY COALESCE(sqlstate, '') "
|
||||
"ORDER BY COALESCE(sqlstate, '')";
|
||||
|
||||
PGresult* res = PQexec(conn, query.c_str());
|
||||
if (res == nullptr) {
|
||||
diag("SQLSTATE count query returned null result: %s", table_name.c_str());
|
||||
return false;
|
||||
}
|
||||
if (PQresultStatus(res) != PGRES_TUPLES_OK) {
|
||||
diag("SQLSTATE count query failed for table %s: %s", table_name.c_str(), PQresultErrorMessage(res));
|
||||
PQclear(res);
|
||||
return false;
|
||||
}
|
||||
|
||||
counts.clear();
|
||||
for (int i = 0; i < PQntuples(res); ++i) {
|
||||
const std::string sqlstate = PQgetvalue(res, i, 0);
|
||||
const int count = atoi(PQgetvalue(res, i, 1));
|
||||
counts[sqlstate] = count;
|
||||
}
|
||||
|
||||
PQclear(res);
|
||||
return true;
|
||||
}
|
||||
|
||||
int main() {
|
||||
CommandLine cl;
|
||||
if (cl.getEnv()) {
|
||||
diag("Failed to get the required environmental variables.");
|
||||
return -1;
|
||||
}
|
||||
|
||||
const unsigned int num_selects = 200;
|
||||
const std::vector<std::string> expected_columns = {
|
||||
"id", "thread_id", "username", "database", "start_time", "end_time", "query_digest",
|
||||
"query", "server", "client", "event_type", "hid", "extra_info", "affected_rows",
|
||||
"rows_sent", "client_stmt_name", "sqlstate", "error"
|
||||
};
|
||||
|
||||
unsigned int p = 2; // table column checks
|
||||
p += num_selects / 10; // successful SELECT checks
|
||||
p += 3; // error checks
|
||||
p += 10; // row accounting + SQLSTATE checks
|
||||
plan(p);
|
||||
|
||||
std::stringstream admin_ss;
|
||||
admin_ss << "host=" << cl.pgsql_admin_host
|
||||
<< " port=" << cl.pgsql_admin_port
|
||||
<< " user=" << cl.admin_username
|
||||
<< " password=" << cl.admin_password
|
||||
<< " dbname=postgres";
|
||||
PGConnPtr admin_conn = create_connection(admin_ss.str());
|
||||
if (!admin_conn) {
|
||||
return -1;
|
||||
}
|
||||
|
||||
ok(
|
||||
check_columns(admin_conn.get(), "SELECT * FROM stats_pgsql_query_events LIMIT 0", expected_columns),
|
||||
"stats_pgsql_query_events columns match expectation"
|
||||
);
|
||||
ok(
|
||||
check_columns(admin_conn.get(), "SELECT * FROM history_pgsql_query_events LIMIT 0", expected_columns),
|
||||
"history_pgsql_query_events columns match expectation"
|
||||
);
|
||||
|
||||
if (!exec_ok(admin_conn.get(), "SET pgsql-eventslog_buffer_history_size=1000000")) return EXIT_FAILURE;
|
||||
if (!exec_ok(admin_conn.get(), "SET pgsql-eventslog_default_log=1")) return EXIT_FAILURE;
|
||||
if (!exec_ok(admin_conn.get(), "LOAD PGSQL VARIABLES TO RUNTIME")) return EXIT_FAILURE;
|
||||
if (!exec_ok(admin_conn.get(), "DUMP PGSQL EVENTSLOG FROM BUFFER TO BOTH")) return EXIT_FAILURE;
|
||||
if (!exec_ok(admin_conn.get(), "DELETE FROM stats_pgsql_query_events")) return EXIT_FAILURE;
|
||||
if (!exec_ok(admin_conn.get(), "DELETE FROM history_pgsql_query_events")) return EXIT_FAILURE;
|
||||
|
||||
std::stringstream proxy_ss;
|
||||
proxy_ss << "host=" << cl.pgsql_host
|
||||
<< " port=" << cl.pgsql_port
|
||||
<< " user=" << cl.pgsql_username
|
||||
<< " password=" << cl.pgsql_password;
|
||||
PGConnPtr proxy_conn = create_connection(proxy_ss.str());
|
||||
if (!proxy_conn) {
|
||||
return -1;
|
||||
}
|
||||
|
||||
for (unsigned int i = 0; i < num_selects; ++i) {
|
||||
PGresult* res = PQexec(proxy_conn.get(), "SELECT 1");
|
||||
bool q_ok = (res != nullptr && PQresultStatus(res) == PGRES_TUPLES_OK);
|
||||
if (!q_ok) {
|
||||
diag("SELECT 1 failed at iteration %u: %s", i + 1, (res ? PQresultErrorMessage(res) : "null result"));
|
||||
if (res) PQclear(res);
|
||||
return EXIT_FAILURE;
|
||||
}
|
||||
PQclear(res);
|
||||
if ((i + 1) % 10 == 0) {
|
||||
ok(1, "SELECT 1 query successful (iteration %u)", i + 1);
|
||||
}
|
||||
}
|
||||
|
||||
{
|
||||
PGresult* res = PQexec(proxy_conn.get(), "SELEEEEECT 1");
|
||||
const char* sqlstate = (res ? PQresultErrorField(res, PG_DIAG_SQLSTATE) : nullptr);
|
||||
ok(res && PQresultStatus(res) == PGRES_FATAL_ERROR && sqlstate && std::string(sqlstate) == "42601",
|
||||
"Syntax error captured with SQLSTATE 42601");
|
||||
if (res) PQclear(res);
|
||||
}
|
||||
|
||||
{
|
||||
PGresult* res = PQexec(proxy_conn.get(), "SELECT * FROM pgsql_non_existing_table_advanced_logging_test");
|
||||
const char* sqlstate = (res ? PQresultErrorField(res, PG_DIAG_SQLSTATE) : nullptr);
|
||||
ok(res && PQresultStatus(res) == PGRES_FATAL_ERROR && sqlstate && std::string(sqlstate) == "42P01",
|
||||
"Undefined table error captured with SQLSTATE 42P01");
|
||||
if (res) PQclear(res);
|
||||
}
|
||||
|
||||
{
|
||||
PGresult* res = PQexec(proxy_conn.get(), "SELECT 1/0");
|
||||
const char* sqlstate = (res ? PQresultErrorField(res, PG_DIAG_SQLSTATE) : nullptr);
|
||||
ok(res && PQresultStatus(res) == PGRES_FATAL_ERROR && sqlstate && std::string(sqlstate) == "22012",
|
||||
"Division by zero error captured with SQLSTATE 22012");
|
||||
if (res) PQclear(res);
|
||||
}
|
||||
|
||||
if (!exec_ok(admin_conn.get(), "DUMP PGSQL EVENTSLOG FROM BUFFER TO BOTH")) return EXIT_FAILURE;
|
||||
|
||||
const long long expected_total = static_cast<long long>(num_selects) + 3;
|
||||
long long history_total = -1;
|
||||
long long stats_total = -1;
|
||||
long long history_success = -1;
|
||||
long long stats_success = -1;
|
||||
long long history_error_msg_missing = -1;
|
||||
long long stats_error_msg_missing = -1;
|
||||
|
||||
ok(
|
||||
query_one_int(admin_conn.get(), "SELECT COUNT(*) FROM history_pgsql_query_events", history_total) &&
|
||||
history_total == expected_total,
|
||||
"history_pgsql_query_events row count matches expectation"
|
||||
);
|
||||
ok(
|
||||
query_one_int(admin_conn.get(), "SELECT COUNT(*) FROM stats_pgsql_query_events", stats_total) &&
|
||||
stats_total == expected_total,
|
||||
"stats_pgsql_query_events row count matches expectation"
|
||||
);
|
||||
ok(
|
||||
query_one_int(admin_conn.get(), "SELECT COUNT(*) FROM history_pgsql_query_events WHERE sqlstate IS NULL", history_success) &&
|
||||
history_success == static_cast<long long>(num_selects),
|
||||
"history_pgsql_query_events success row count matches expectation"
|
||||
);
|
||||
ok(
|
||||
query_one_int(admin_conn.get(), "SELECT COUNT(*) FROM stats_pgsql_query_events WHERE sqlstate IS NULL", stats_success) &&
|
||||
stats_success == static_cast<long long>(num_selects),
|
||||
"stats_pgsql_query_events success row count matches expectation"
|
||||
);
|
||||
|
||||
std::map<std::string, int> expected_sqlstate_counts = {
|
||||
{"", static_cast<int>(num_selects)},
|
||||
{"22012", 1},
|
||||
{"42601", 1},
|
||||
{"42P01", 1}
|
||||
};
|
||||
std::map<std::string, int> history_sqlstate_counts;
|
||||
std::map<std::string, int> stats_sqlstate_counts;
|
||||
|
||||
ok(
|
||||
get_sqlstate_counts(admin_conn.get(), "history_pgsql_query_events", history_sqlstate_counts) &&
|
||||
history_sqlstate_counts == expected_sqlstate_counts,
|
||||
"history_pgsql_query_events SQLSTATE distribution matches expectation"
|
||||
);
|
||||
ok(
|
||||
get_sqlstate_counts(admin_conn.get(), "stats_pgsql_query_events", stats_sqlstate_counts) &&
|
||||
stats_sqlstate_counts == expected_sqlstate_counts,
|
||||
"stats_pgsql_query_events SQLSTATE distribution matches expectation"
|
||||
);
|
||||
|
||||
ok(
|
||||
query_one_int(
|
||||
admin_conn.get(),
|
||||
"SELECT COUNT(*) FROM history_pgsql_query_events WHERE sqlstate IS NOT NULL AND (error IS NULL OR error='')",
|
||||
history_error_msg_missing
|
||||
) && history_error_msg_missing == 0,
|
||||
"history_pgsql_query_events has non-empty error messages for error rows"
|
||||
);
|
||||
ok(
|
||||
query_one_int(
|
||||
admin_conn.get(),
|
||||
"SELECT COUNT(*) FROM stats_pgsql_query_events WHERE sqlstate IS NOT NULL AND (error IS NULL OR error='')",
|
||||
stats_error_msg_missing
|
||||
) && stats_error_msg_missing == 0,
|
||||
"stats_pgsql_query_events has non-empty error messages for error rows"
|
||||
);
|
||||
|
||||
ok(
|
||||
exec_ok(admin_conn.get(), "DUMP PGSQL EVENTSLOG FROM BUFFER TO MEMORY"),
|
||||
"DUMP PGSQL EVENTSLOG FROM BUFFER TO MEMORY succeeds"
|
||||
);
|
||||
ok(
|
||||
exec_ok(admin_conn.get(), "DUMP PGSQL EVENTSLOG FROM BUFFER TO DISK"),
|
||||
"DUMP PGSQL EVENTSLOG FROM BUFFER TO DISK succeeds"
|
||||
);
|
||||
|
||||
return exit_status();
|
||||
}
|
||||
Loading…
Reference in new issue