Skip to content

Commit f892d8e

Browse files
malone-at-workmalone-at-work
committed
vef: Add Query Hook Capability
Read-only query hooks are called at one of five times with relevant metadata: A) Session connect B) Before query is parsed C) After query is parsed D) Before query exection E) After query execution F) Session disconnect Only (E) after query execution is implemented in this change.
1 parent 17d0973 commit f892d8e

16 files changed

Lines changed: 915 additions & 0 deletions

File tree

‎mysql-test/suite/villagesql/extension/vsql-slow-query-log/r/slow_query_log_basic.result‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
SET PERSIST vsql_allow_preview_extensions = ON;
2+
INSTALL EXTENSION vsql_slow_query_log;
3+
SET GLOBAL vsql_slow_query_log.threshold_ms = 100;
4+
SET GLOBAL vsql_slow_query_log.log_file = 'MYSQLTEST_VARDIR/tmp/vsql_slow.log';
5+
SET GLOBAL vsql_slow_query_log.enabled = ON;
6+
# Slow query (>= 100ms) should be logged
7+
SELECT SLEEP(0.3) AS slow_marker;
8+
slow_marker
9+
0
10+
# Fast query should NOT be logged
11+
SELECT 1 AS fast_marker;
12+
fast_marker
13+
1
14+
SET GLOBAL vsql_slow_query_log.enabled = OFF;
15+
# While disabled, even slow queries should NOT be logged
16+
SELECT SLEEP(0.3) AS disabled_marker;
17+
disabled_marker
18+
0
19+
# Exactly one SLEEP entry (from the enabled period) is in the log
20+
1
21+
# The fast query did not get logged
22+
0
23+
# The disabled query did not get logged
24+
0
25+
# When log_file points at a non-existent directory, the hook's fopen
26+
# fails and reports via result.error_msg(). The server logs that as a
27+
# Warning in the error log.
28+
call mtr.add_suppression("Query hook error in extension 'vsql_slow_query_log'");
29+
SET GLOBAL vsql_slow_query_log.log_file = '/tmp/vsql_slow_query_log_uaf_test_dir_xyz/slow.log';
30+
SET GLOBAL vsql_slow_query_log.enabled = ON;
31+
SELECT SLEEP(0.3) AS unwritable_marker;
32+
unwritable_marker
33+
0
34+
SET GLOBAL vsql_slow_query_log.enabled = OFF;
35+
# Exactly one warning containing the unique path token
36+
1
37+
UNINSTALL EXTENSION vsql_slow_query_log;
38+
SET PERSIST vsql_allow_preview_extensions = OFF;
39+
RESET PERSIST vsql_allow_preview_extensions;

‎mysql-test/suite/villagesql/extension/vsql-slow-query-log/t/slow_query_log_basic.test‎

Lines changed: 70 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,70 @@
1+
# Test the vsql_slow_query_log extension.
2+
#
3+
# Verifies:
4+
# - INSTALL EXTENSION registers the slow query log hook
5+
# - Queries exceeding threshold_ms are written to log_file
6+
# - Queries under threshold_ms are NOT written
7+
# - Disabling 'enabled' silences the hook
8+
# - When log_file cannot be opened, the hook reports an error via
9+
# QueryHookResult::error_msg() and the server logs it
10+
# - UNINSTALL EXTENSION removes the hook cleanly
11+
12+
# Unique token for the unwritable-path error message so the grep can't
13+
# accidentally match an unrelated line in a long error log.
14+
--let $error_log = $MYSQLTEST_VARDIR/log/mysqld.1.err
15+
--let $bad_log_path = /tmp/vsql_slow_query_log_uaf_test_dir_xyz/slow.log
16+
--let $slow_log = $MYSQLTEST_VARDIR/tmp/vsql_slow.log
17+
18+
SET PERSIST vsql_allow_preview_extensions = ON;
19+
20+
# Clean any stale log file from a previous run.
21+
--error 0,1
22+
--remove_file $slow_log
23+
24+
INSTALL EXTENSION vsql_slow_query_log;
25+
26+
SET GLOBAL vsql_slow_query_log.threshold_ms = 100;
27+
--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
28+
eval SET GLOBAL vsql_slow_query_log.log_file = '$slow_log';
29+
SET GLOBAL vsql_slow_query_log.enabled = ON;
30+
31+
--echo # Slow query (>= 100ms) should be logged
32+
SELECT SLEEP(0.3) AS slow_marker;
33+
34+
--echo # Fast query should NOT be logged
35+
SELECT 1 AS fast_marker;
36+
37+
SET GLOBAL vsql_slow_query_log.enabled = OFF;
38+
39+
--echo # While disabled, even slow queries should NOT be logged
40+
SELECT SLEEP(0.3) AS disabled_marker;
41+
42+
# grep -c exits 1 when it finds zero matches (still prints "0"). Wrap in
43+
# sh -c "...; true" so mysqltest sees a success exit code regardless.
44+
--echo # Exactly one SLEEP entry (from the enabled period) is in the log
45+
--exec sh -c "grep -c 'slow_marker' $slow_log; true"
46+
47+
--echo # The fast query did not get logged
48+
--exec sh -c "grep -c 'fast_marker' $slow_log; true"
49+
50+
--echo # The disabled query did not get logged
51+
--exec sh -c "grep -c 'disabled_marker' $slow_log; true"
52+
53+
--echo # When log_file points at a non-existent directory, the hook's fopen
54+
--echo # fails and reports via result.error_msg(). The server logs that as a
55+
--echo # Warning in the error log.
56+
call mtr.add_suppression("Query hook error in extension 'vsql_slow_query_log'");
57+
eval SET GLOBAL vsql_slow_query_log.log_file = '$bad_log_path';
58+
SET GLOBAL vsql_slow_query_log.enabled = ON;
59+
SELECT SLEEP(0.3) AS unwritable_marker;
60+
SET GLOBAL vsql_slow_query_log.enabled = OFF;
61+
62+
--echo # Exactly one warning containing the unique path token
63+
--exec sh -c "grep -c 'vsql_slow_query_log_uaf_test_dir_xyz' $error_log; true"
64+
65+
UNINSTALL EXTENSION vsql_slow_query_log;
66+
67+
SET PERSIST vsql_allow_preview_extensions = OFF;
68+
RESET PERSIST vsql_allow_preview_extensions;
69+
70+
--remove_file $slow_log

‎sql/sql_audit.cc‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
/* Copyright (c) 2007, 2026, Oracle and/or its affiliates.
2+
Copyright (c) 2026 VillageSQL Contributors
23
34
This program is free software; you can redistribute it and/or modify
45
it under the terms of the GNU General Public License, version 2.0,
@@ -63,6 +64,7 @@
6364
#include "sql_string.h"
6465
#include "strxnmov.h"
6566
#include "thr_mutex.h"
67+
#include "villagesql/services/preview/query_hook.h"
6668

6769
namespace {
6870
/**
@@ -1094,6 +1096,9 @@ int mysql_event_tracking_query_notify(
10941096
const char *subclass_name) {
10951097
mysql_event_tracking_query_data event;
10961098

1099+
if (subclass & EVENT_TRACKING_QUERY_STATUS_END)
1100+
villagesql::services::on_query_status_end(thd);
1101+
10971102
if (thd->check_event_subscribers(Event_tracking_class::QUERY, subclass, true))
10981103
return 0;
10991104

‎villagesql/CMakeLists.txt‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -182,6 +182,15 @@ IF(NOT WITHOUT_SERVER)
182182
BINARY_BASE ${CMAKE_CURRENT_BINARY_DIR}/examples
183183
INSTALL_DEST ${INSTALL_VEBDIR}
184184
)
185+
vsql_add_extension(
186+
DIR_NAME vsql-slow-query-log
187+
EXT_TARGET vsql_slow_query_log_extension
188+
VEB_NAME vsql_slow_query_log
189+
SOURCE_BASE ${CMAKE_CURRENT_SOURCE_DIR}/examples
190+
BINARY_BASE ${CMAKE_CURRENT_BINARY_DIR}/examples
191+
INSTALL_DEST ${INSTALL_VEBDIR}
192+
INSTALL_COMPONENT ExampleVebs
193+
)
185194

186195
# Test extensions (share a single CMakeLists.txt template)
187196
vsql_add_test_extension(vsql-config-vars-test vsql_config_vars_test)

‎villagesql/examples/vsql-slow-query-log/CMakeLists.txt‎

Lines changed: 54 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,54 @@
1+
# Copyright (c) 2026 VillageSQL Contributors
2+
#
3+
# This program is free software; you can redistribute it and/or modify
4+
# it under the terms of the GNU General Public License, version 2.0,
5+
# as published by the Free Software Foundation.
6+
#
7+
# This program is designed to work with certain software (including
8+
# but not limited to OpenSSL) that is licensed under separate terms,
9+
# as designated in a particular file or component or in included license
10+
# documentation. The authors of MySQL hereby grant you an additional
11+
# permission to link the program and your derivative works with the
12+
# separately licensed software that they have either included with
13+
# the program or referenced in the documentation.
14+
#
15+
# This program is distributed in the hope that it will be useful,
16+
# but WITHOUT ANY WARRANTY; without even the implied warranty of
17+
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
18+
# GNU General Public License, version 2.0, for more details.
19+
#
20+
# You should have received a copy of the GNU General Public License
21+
# along with this program; if not, write to the Free Software
22+
# Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
23+
24+
# Quick start (standalone):
25+
# mkdir build && cd build
26+
# cmake .. -DCMAKE_PREFIX_PATH=/path/to/villagesql-extension-sdk
27+
# make
28+
# make install DESTDIR=/path/to/villagesql/lib/veb
29+
30+
cmake_minimum_required(VERSION 3.16)
31+
project(vsql_slow_query_log_extension)
32+
33+
set(CMAKE_CXX_STANDARD 17)
34+
set(CMAKE_CXX_STANDARD_REQUIRED ON)
35+
36+
set(EXTENSION_NAME "vsql_slow_query_log")
37+
38+
find_package(VillageSQLExtensionFramework REQUIRED)
39+
40+
include_directories(${VillageSQLExtensionFramework_INCLUDE_DIR})
41+
42+
add_library(extension SHARED
43+
src/extension.cc
44+
)
45+
46+
target_compile_options(extension PRIVATE -fPIC)
47+
48+
VEF_CREATE_VEB(
49+
NAME ${EXTENSION_NAME}
50+
LIBRARY_TARGET extension
51+
MANIFEST ${CMAKE_CURRENT_SOURCE_DIR}/manifest.json
52+
)
53+
54+
install(FILES ${VEB_OUTPUT} DESTINATION ".")

‎villagesql/examples/vsql-slow-query-log/manifest.json‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,7 @@
1+
{
2+
"name": "vsql_slow_query_log",
3+
"version": "0.0.1",
4+
"description": "Logs queries exceeding a configurable threshold to a log file",
5+
"author": "VillageSQL Community",
6+
"license": "GPL-2.0"
7+
}

‎villagesql/examples/vsql-slow-query-log/src/extension.cc‎

Lines changed: 104 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,104 @@
1+
// Copyright (c) 2026 VillageSQL Contributors
2+
//
3+
// This program is free software; you can redistribute it and/or modify
4+
// it under the terms of the GNU General Public License, version 2.0,
5+
// as published by the Free Software Foundation.
6+
//
7+
// This program is designed to work with certain software (including
8+
// but not limited to OpenSSL) that is licensed under separate terms,
9+
// as designated in a particular file or component or in included license
10+
// documentation. The authors of MySQL hereby grant you an additional
11+
// permission to link the program and your derivative works with the
12+
// separately licensed software that they have either included with
13+
// the program or referenced in the documentation.
14+
//
15+
// This program is distributed in the hope that it will be useful,
16+
// but WITHOUT ANY WARRANTY; without even the implied warranty of
17+
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
18+
// GNU General Public License, version 2.0, for more details.
19+
//
20+
// You should have received a copy of the GNU General Public License
21+
// along with this program; if not, write to the Free Software
22+
// Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
23+
24+
// VillageSQL slow query log extension.
25+
//
26+
// Logs queries exceeding vsql_slow_query_log.threshold_ms to
27+
// vsql_slow_query_log.log_file. Disabled by default; enable with
28+
// SET GLOBAL vsql_slow_query_log.enabled = ON;
29+
30+
#include <cerrno>
31+
#include <cstdint>
32+
#include <cstdio>
33+
#include <cstring>
34+
#include <ctime>
35+
#include <mutex>
36+
37+
#include <villagesql/preview/query_hook.h>
38+
#include <villagesql/preview/sys_var.h>
39+
#include <villagesql/vsql.h>
40+
41+
using namespace vsql;
42+
namespace sv = vsql::preview_sys_var;
43+
namespace qh = vsql::preview_query_hook;
44+
45+
static bool g_enabled;
46+
static long long g_threshold_ms;
47+
static char *g_log_filename;
48+
49+
static std::mutex g_log_mutex;
50+
51+
static void slow_query_hook(const qh::QueryHookArgs &args,
52+
qh::QueryHookResult &result) {
53+
if (!g_enabled) return;
54+
if (args.query_time_secs() * 1000.0 < static_cast<double>(g_threshold_ms))
55+
return;
56+
57+
time_t now = static_cast<time_t>(args.query_start_utime() / 1000000);
58+
uint32_t usec = static_cast<uint32_t>(args.query_start_utime() % 1000000);
59+
struct tm tm_buf;
60+
gmtime_r(&now, &tm_buf);
61+
char ts[48];
62+
strftime(ts, sizeof(ts), "%Y-%m-%dT%H:%M:%S.", &tm_buf);
63+
snprintf(ts + 20, sizeof(ts) - 20, "%06uZ", usec);
64+
65+
std::lock_guard<std::mutex> lock(g_log_mutex);
66+
FILE *f = fopen(g_log_filename, "a");
67+
if (f == nullptr) {
68+
result.error_msg("failed to open '%s': %s", g_log_filename,
69+
strerror(errno));
70+
return;
71+
}
72+
73+
fprintf(f, "# Time: %s\n", ts);
74+
fprintf(f, "# User@Host: %s @ %s Id: %lu\n", args.user() ? args.user() : "",
75+
args.host() ? args.host() : "", args.connection_id());
76+
fprintf(f,
77+
"# Schema: %s Query_time: %.6f Lock_time: %.6f"
78+
" Rows_sent: %llu Rows_examined: %llu\n",
79+
args.schema() ? args.schema() : "", args.query_time_secs(),
80+
args.lock_time_secs(), (unsigned long long)args.rows_sent(),
81+
(unsigned long long)args.rows_examined());
82+
fprintf(f, "SET timestamp=%llu;\n", (unsigned long long)now);
83+
auto q = args.query();
84+
fprintf(f, "%.*s;\n", (int)q.size(), q.data());
85+
fclose(f);
86+
}
87+
88+
static auto SYS_VARS = sv::make_capability({
89+
sv::make_bool("enabled",
90+
"Enable or disable the slow query log (default: OFF)",
91+
&g_enabled, false),
92+
sv::make_int("threshold_ms",
93+
"Minimum query execution time in ms to log (default: 1000)",
94+
&g_threshold_ms, 1000, 0, 3600000),
95+
sv::make_str("log_file",
96+
"Path to the slow query log file "
97+
"(default: /tmp/vsql_slow_query.log)",
98+
&g_log_filename, "/tmp/vsql_slow_query.log"),
99+
});
100+
101+
static qh::QueryHookCapability<VEF_QUERY_HOOK_POSTEXECUTE, &slow_query_hook>
102+
QUERY_HOOK;
103+
104+
VEF_GENERATE_ENTRY_POINTS(make_extension().with(SYS_VARS).with(QUERY_HOOK))

0 commit comments

Comments
 (0)