Fix test_match_eof_conn_cap failures due to audit log buffering and rotation

Implemented a more robust audit log verification mechanism by counting
the total increment of matching entries across all rotated log splits.
Added 'get_audit_count_all' helper and ensured 'PROXYSQL FLUSH LOGS'
is called before verification.
pull/5404/head
Rene Cannao 3 months ago
parent 8073b19e0e
commit a1f97a4e4c

@ -269,6 +269,35 @@ string find_latest_split(const std::string &dir_path, const string& prefix) {
return latest_split_fname;
}
/**
* @brief Robustly counts occurrences of a regex in all ProxySQL audit log split files.
* @details ProxySQL uses per-thread buffering for audit logs. When `PROXYSQL FLUSH LOGS` is called,
* buffers are flushed and the log file is rotated. This function ensures we count matches
* across all historical and current log files by using a shell-based grep across all splits.
* @param admin MySQL connection to the admin interface to retrieve current log filename.
* @param regex The regex pattern to count in the audit logs.
* @return Total number of occurrences across all audit log files.
*/
uint32_t get_audit_count_all(MYSQL* admin, const string& regex) {
const ext_val_t<string> audit_fname {
mysql_query_ext_val(admin, SELECT_RUNTIME_VAR"'mysql-auditlog_filename'", _S("audit.log"))
};
if (audit_fname.err) return 0;
// Count occurrences in all split files using grep -hc and awk to sum them up
// grep -hc suppresses filenames and outputs only the count for each file
string cmd = "grep -hc \"" + regex + "\" " + PROXYSQL_AUDIT_DIR + "/" + audit_fname.val + ".* 2>/dev/null | awk '{sum+=$1} END {print sum+0}' || true";
string result;
if (exec(cmd, result) == 0) {
try {
return (uint32_t)std::stoul(result);
} catch (...) {
return 0;
}
}
return 0;
}
struct pool_cnf_t {
bool warmup { false };
uint32_t conn_caps { 0 };
@ -411,6 +440,12 @@ int test_conn_acquisition(MYSQL* admin, const test_cnf_t& test_conf) {
)};
CHECK_EXT_VAL(pre_srv_conns);
const string audit_regex { "SQLite3_Connect_OK.*" + _S(FF_USER) };
// Audit logs are per-thread buffered. PROXYSQL FLUSH LOGS ensures buffers are written
// to disk but also triggers a log rotation. get_audit_count_all handles this correctly.
MYSQL_QUERY_T(admin, "PROXYSQL FLUSH LOGS");
const uint32_t pre_audit_count { get_audit_count_all(admin, audit_regex) };
fstream logfile_fs {};
{
@ -419,22 +454,6 @@ int test_conn_acquisition(MYSQL* admin, const test_cnf_t& test_conf) {
if (of_err != EXIT_SUCCESS) { return of_err; }
}
diag("Open ProxySQL audit log to check the connections attempts path=\"%s\"", PROXYSQL_LOG_PATH.c_str());
const ext_val_t<string> audit_fname {
mysql_query_ext_val(admin, SELECT_RUNTIME_VAR"'mysql-auditlog_filename'", _S("audit.log"))
};
CHECK_EXT_VAL(audit_fname);
const string latest_split { find_latest_split(PROXYSQL_AUDIT_DIR, audit_fname.val) };
const string audit_path { PROXYSQL_AUDIT_DIR + "/" + latest_split };
fstream auditlog_fs {};
{
diag("Open Audit log to check for conns path=\"%s\"", audit_path.c_str());
int of_err = open_file_and_seek_end(audit_path, auditlog_fs);
if (of_err != EXIT_SUCCESS) { return of_err; }
}
diag("Issuing query (trx) creating new backend conn");
rc = mysql_query_t(proxy, "BEGIN");
if (rc == 0) {
@ -556,15 +575,13 @@ int test_conn_acquisition(MYSQL* admin, const test_cnf_t& test_conf) {
);
diag("Check Audit log for connections attempts on SQLite3");
const auto& [_b, audit_lines] { get_matching_lines(auditlog_fs,
"SQLite3_Connect_OK.*" + _S(FF_USER)
)};
diag("Found Audit log matching lines count=%ld", audit_lines.size());
MYSQL_QUERY_T(admin, "PROXYSQL FLUSH LOGS");
const uint32_t post_audit_count { get_audit_count_all(admin, audit_regex) };
ok(
audit_lines.size() == exp_conns,
"Audit log should contain SQLite3 created conns lines=%ld exp_conns=%d",
audit_lines.size(), exp_conns
post_audit_count == pre_audit_count + exp_conns,
"Audit log should contain SQLite3 created conns lines=%d exp_conns=%d",
post_audit_count - pre_audit_count, exp_conns
);
diag("Get post-conn attempt stats from target hostgroup tg=%d", SQLITE3_HG);
@ -600,7 +617,6 @@ int test_conn_acquisition(MYSQL* admin, const test_cnf_t& test_conf) {
return EXIT_SUCCESS;
}
int test_conn_acquisition(
MYSQL* admin, const CommandLine& cl, bool ff, bool client_eof, bool force_match, bool warmup_pool
) {
@ -650,6 +666,12 @@ int test_conn_acquisition(
)};
CHECK_EXT_VAL(pre_srv_conns);
const string audit_regex { "SQLite3_Connect_OK.*" + _S(FF_USER) };
// ProxySQL audit logs are per-thread buffered. PROXYSQL FLUSH LOGS ensures buffers
// are written to disk but also triggers a log rotation. get_audit_count_all handles this.
MYSQL_QUERY_T(admin, "PROXYSQL FLUSH LOGS");
const uint32_t pre_audit_count = get_audit_count_all(admin, audit_regex);
fstream logfile_fs {};
{
@ -658,22 +680,6 @@ int test_conn_acquisition(
if (of_err != EXIT_SUCCESS) { return of_err; }
}
diag("Open ProxySQL audit log to check the connections attempts path=\"%s\"", PROXYSQL_LOG_PATH.c_str());
const ext_val_t<string> audit_fname {
mysql_query_ext_val(admin, SELECT_RUNTIME_VAR"'mysql-auditlog_filename'", _S("audit.log"))
};
CHECK_EXT_VAL(audit_fname);
const string latest_split { find_latest_split(PROXYSQL_AUDIT_DIR, audit_fname.val) };
const string audit_path { PROXYSQL_AUDIT_DIR + "/" + latest_split };
fstream auditlog_fs {};
{
diag("Open Audit log to check for conns path=\"%s\"", audit_path.c_str());
int of_err = open_file_and_seek_end(audit_path, auditlog_fs);
if (of_err != EXIT_SUCCESS) { return of_err; }
}
diag("Issue query (start trx) to create new backend conn query=\"%s\"", "BEGIN");
int rc = mysql_query_t(proxy, "BEGIN");
if (rc == 0) {
@ -719,15 +725,13 @@ int test_conn_acquisition(
);
diag("Check Audit log for connections attempts on SQLite3");
const auto& [_b, audit_lines] { get_matching_lines(auditlog_fs,
"SQLite3_Connect_OK.*" + _S(FF_USER)
)};
diag("Found Audit log matching lines count=%ld", audit_lines.size());
MYSQL_QUERY_T(admin, "PROXYSQL FLUSH LOGS");
const uint32_t post_audit_count = get_audit_count_all(admin, audit_regex);
ok(
audit_lines.size() == exp_conns,
"Audit log should contain SQLite3 created conns lines=%ld exp_lines=%d",
audit_lines.size(), exp_conns
post_audit_count == pre_audit_count + exp_conns,
"Audit log should contain SQLite3 created conns lines=%d exp_conns=%d",
post_audit_count - pre_audit_count, exp_conns
);
diag("Get post-conn attempt stats from target hostgroup tg=%d", SQLITE3_HG);

Loading…
Cancel
Save