Add working TAP test for TCP keepalive warnings (issue #5212)

- Implement get_matching_lines_from_filename() with efficient queue-based processing
- Use standard C++ regex instead of RE2 for reliable pattern matching
- Add filename-based function to avoid stream sharing conflicts
- Remove problematic stream-based function with max_lines parameter
- Fix regex pattern to match actual log warning format
- Add comprehensive debugging output (disabled with #if 0)
- Test both MySQL and PostgreSQL TCP keepalive warnings
- Search only last 10 lines for efficiency and relevance

The test now correctly verifies that TCP keepalive warnings are logged
when mysql-use_tcp_keepalive or pgsql-use_tcp_keepalive is set to false.
pull/5228/head
Rene Cannao 6 months ago
parent e54e3c8df3
commit b1a1930e1c

@ -1,6 +1,7 @@
#include <algorithm>
#include <chrono>
#include <cstring>
#include <deque>
#include <fcntl.h>
#include <iostream>
#include <numeric>
@ -13,6 +14,7 @@
#include "json.hpp"
#include "re2/re2.h"
#include <regex>
#include "proxysql_utils.h"
@ -1627,59 +1629,82 @@ pair<size_t,vector<line_match_t>> get_matching_lines(
return { insp_lines, found_matches };
}
pair<size_t,vector<line_match_t>> get_matching_lines(
fstream& f_stream, const string& s_regex, bool get_matches, size_t max_lines
std::pair<size_t,std::vector<line_match_t>> get_matching_lines_from_filename(
const std::string& filename, const std::string& s_regex, bool get_matches, size_t max_lines
) {
vector<line_match_t> found_matches {};
vector<string> recent_lines {};
size_t insp_lines { 0 };
string next_line {};
fstream::pos_type init_pos { f_stream.tellg() };
// First, read the last max_lines from the file
vector<string> all_lines {};
while (getline(f_stream, next_line)) {
all_lines.push_back(next_line);
// Open file for reading
std::ifstream file(filename);
if (!file.is_open()) {
diag("get_matching_lines_from_filename ERROR: Cannot open file '%s'", filename.c_str());
return { 0, found_matches };
}
// Get only the last max_lines (or fewer if file has less lines)
size_t start_idx = 0;
if (all_lines.size() > max_lines) {
start_idx = all_lines.size() - max_lines;
// Read file line by line, keeping only the last max_lines in a queue
std::deque<string> recent_lines {};
size_t total_lines_read = 0;
string next_line;
while (getline(file, next_line)) {
total_lines_read++;
// Add to queue and maintain size
recent_lines.push_back(next_line);
if (recent_lines.size() > max_lines) {
recent_lines.pop_front();
}
}
// Process only the recent lines
for (size_t i = start_idx; i < all_lines.size(); i++) {
next_line = all_lines[i];
insp_lines++;
// Create regex object once before the loop
std::regex regex;
try {
regex = std::regex(s_regex);
} catch (const std::regex_error& e) {
diag("get_matching_lines_from_filename ERROR: Invalid regex '%s': %s", s_regex.c_str(), e.what());
return { 0, found_matches };
}
re2::RE2 regex { s_regex };
re2::StringPiece match;
// Process the recent lines from the queue
for (const string& line : recent_lines) {
std::smatch match;
if (get_matches) {
if (RE2::PartialMatch(next_line, regex, &match)) {
found_matches.push_back({ f_stream.tellg(), next_line, match.ToString() });
if (std::regex_search(line, match, regex)) {
found_matches.push_back({ static_cast<fstream::pos_type>(0), line, match.str() });
}
} else {
if (RE2::PartialMatch(next_line, regex)) {
found_matches.push_back({ f_stream.tellg(), next_line, "" });
if (std::regex_search(line, regex)) {
found_matches.push_back({ static_cast<fstream::pos_type>(0), line, "" });
}
}
}
if (found_matches.empty() == false) {
const string& last_match { std::get<LINE_MATCH_T::LINE>(found_matches.back()) };
const fstream::pos_type last_match_pos { std::get<LINE_MATCH_T::POS>(found_matches.back()) };
// Debug output
diag("get_matching_lines_from_filename DEBUG: filename='%s', total_lines_read=%zu, max_lines=%zu, lines_examined=%zu, matches_found=%zu",
filename.c_str(), total_lines_read, max_lines, recent_lines.size(), found_matches.size());
f_stream.clear(f_stream.rdstate() & ~std::ios_base::failbit);
f_stream.seekg(last_match_pos);
} else {
f_stream.clear(f_stream.rdstate() & ~std::ios_base::failbit);
f_stream.seekg(init_pos);
#if 0
// Print the last lines being examined for debugging
diag("=== DEBUG: Last %zu lines examined from '%s' ===", recent_lines.size(), filename.c_str());
for (size_t i = 0; i < recent_lines.size(); i++) {
diag("Line %zu: %s", i+1, recent_lines[i].c_str());
}
diag("=== END DEBUG LINES ===");
return { insp_lines, found_matches };
// Print all matching lines for debugging
for (size_t i = 0; i < found_matches.size(); i++) {
const string& match_line = std::get<LINE>(found_matches[i]);
diag("Match %zu: %s", i+1, match_line.c_str());
}
#endif // 0
// Close file
file.close();
// Return actual number of matches found, not lines examined
return { found_matches.size(), found_matches };
}
const uint32_t USLEEP_SQLITE_LOCKED = 100;

@ -766,9 +766,10 @@ std::pair<size_t,std::vector<line_match_t>> get_matching_lines(
std::fstream& f_stream, const std::string& regex, bool get_matches=false
);
// Overload to scan only the last N lines
std::pair<size_t,std::vector<line_match_t>> get_matching_lines(
std::fstream& f_stream, const std::string& regex, bool get_matches, size_t max_lines
// Function to scan last N lines from filename (no stream sharing issues)
std::pair<size_t,std::vector<line_match_t>> get_matching_lines_from_filename(
const std::string& filename, const std::string& regex, bool get_matches, size_t max_lines
);
/**

@ -38,14 +38,6 @@ int main(int argc, char** argv) {
// Test 1: MySQL TCP keepalive warning
diag("Testing MySQL TCP keepalive warning when set to false");
{
fstream logfile {};
int open_err = open_file_and_seek_end(log_path, logfile);
if (open_err != EXIT_SUCCESS) {
diag("Failed to open log file: %s", log_path.c_str());
mysql_close(admin);
return exit_status();
}
// Set MySQL TCP keepalive to false
int query_err = mysql_query(admin, "SET mysql-use_tcp_keepalive='false'");
ok(query_err == 0, "SET mysql-use_tcp_keepalive='false' should succeed");
@ -67,30 +59,20 @@ int main(int argc, char** argv) {
// Wait a bit for the warning to be written to log
usleep(200000); // 200ms
// Check for the warning in the log - scan only last 50 lines
const string warning_regex { ".*\\[WARNING\\].*mysql-use_tcp_keepalive is set to false.*" };
const auto& [match_count, warning_lines] = get_matching_lines(logfile, warning_regex, false, 50);
// Check for the warning in the log - scan only last 10 lines using filename-based function
const string warning_regex { ".*WARNING.*mysql-use_tcp_keepalive is set to false.*" };
const auto& [match_count, warning_lines] = get_matching_lines_from_filename(log_path, warning_regex, true, 10);
// Scanning only last 50 lines ensures we're looking at recent log entries
ok(match_count > 0, "MySQL TCP keepalive warning should appear in log when set to false");
// Scanning only last 10 lines ensures we're looking at recent log entries
ok(match_count > 0, "MySQL TCP keepalive warning should appear in log when set to false");
if (match_count == 0) {
diag("Expected MySQL TCP keepalive warning not found in last 50 lines of log");
} else {
diag("Found %zu MySQL TCP keepalive warning(s) in last 50 lines", match_count);
diag("Expected MySQL TCP keepalive warning not found in last 10 lines of log");
}
}
// Test 2: PostgreSQL TCP keepalive warning
diag("Testing PostgreSQL TCP keepalive warning when set to false");
{
fstream logfile {};
int open_err = open_file_and_seek_end(log_path, logfile);
if (open_err != EXIT_SUCCESS) {
diag("Failed to open log file: %s", log_path.c_str());
mysql_close(admin);
return exit_status();
}
// Set PostgreSQL TCP keepalive to false
int query_err = mysql_query(admin, "SET pgsql-use_tcp_keepalive='false'");
ok(query_err == 0, "SET pgsql-use_tcp_keepalive='false' should succeed");
@ -110,18 +92,16 @@ int main(int argc, char** argv) {
}
// Wait a bit for the warning to be written to log
usleep(200000); // 200ms
usleep(500000); // 500ms
// Check for the warning in the log - scan only last 50 lines
const string warning_regex { ".*\\[WARNING\\].*pgsql-use_tcp_keepalive is set to false.*" };
const auto& [match_count, warning_lines] = get_matching_lines(logfile, warning_regex, false, 50);
// Check for the warning in the log - scan only last 10 lines using filename-based function
const string warning_regex { ".*WARNING.*pgsql-use_tcp_keepalive is set to false.*" };
const auto& [match_count, warning_lines] = get_matching_lines_from_filename(log_path, warning_regex, true, 10);
// Scanning only last 50 lines ensures we're looking at recent log entries
// Scanning only last 10 lines ensures we're looking at recent log entries
ok(match_count > 0, "PostgreSQL TCP keepalive warning should appear in log when set to false");
if (match_count == 0) {
diag("Expected PostgreSQL TCP keepalive warning not found in last 50 lines of log");
} else {
diag("Found %zu PostgreSQL TCP keepalive warning(s) in last 50 lines", match_count);
diag("Expected PostgreSQL TCP keepalive warning not found in last 10 lines of log");
}
}

Loading…
Cancel
Save