feat(mcp): guard time limit and refusal log (RFC 0001 Phase 2, part 2)

CHANGELOG.md

@@ -8,6 +8,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 ## [Unreleased]
 
 ### Added
+- **`component_mcp_guard` time limit and refusal log** (Phase 2 of RFC 0001, completed).
+  - **`mcp.max_execution_time_ms`:** sets an MCP session's `max_execution_time` at connect. Attempts to raise it are refused with error 1290: via `SET`, or via the `MAX_EXECUTION_TIME(n)` or `SET_VAR(max_execution_time=n)` hints. Lowering it is allowed.
+  - **`mcp.log_denials` (default ON):** writes each refusal to the error log as `[MY-011071] [mcp_guard]`, with string literals redacted, at most 10 lines a minute.
+  - **Tests:** `scripts/test-mcp-guard.sh` now has 80 checks, including a 5 s `SELECT` stopped by a 1 s limit, a tightened limit reaching a connected session, literal redaction in the log and the log rate limit on a fresh server, passing on MySQL 8.4.11, 9.7.2 and 26.10.0.
 - **`component_mcp_guard` enforcement** (Phase 2 of [RFC 0001](https://github.com/askdba/mysql-mcp-server/blob/main/docs/rfc/0001-mysql-component-architecture.md)).
   - **MCP sessions:** sessions of accounts holding `MCP_USER` (and not `MCP_ADMIN`) are checked against `mcp.*` settings inside `mysqld`. The checks run on the server's query, table-access and connection events.
   - **`mcp.read_only` (default ON):** only reads, even with write grants. It uses an allowlist of `sql_command` classes and also refuses `SELECT … INTO OUTFILE`, locking reads, `SET GLOBAL` and `CALL` outside `mysql_mcp`.

docs/MCP_COMPONENTS.md

@@ -4,7 +4,7 @@ Server-side components for [mysql-mcp-server](https://github.com/askdba/mysql-mc
 
 | Component | Status | Servers |
 |---|---|---|
-| `component_mcp_guard` | Phase 2: identity, read-only and schema enforcement, status variables | MySQL 8.4, 9.7, 26.10 |
+| `component_mcp_guard` | Phase 2: identity, read-only and schema enforcement, time limit, error log, status variables | MySQL 8.4, 9.7, 26.10 |
 | `mysql_mcp` SQL tool pack ([`sql/mcp/`](https://github.com/askdba/myvector/tree/main/sql/mcp)) | 1.0.0 | MySQL 8.0 to 26.10, MariaDB 11.4, 12.3 |
 
 ## component_mcp_guard
@@ -39,6 +39,8 @@ A session is an **MCP session** when its account holds `MCP_USER` and not `MCP_A
 | `mcp.read_only` | `ON` | Only reads, whatever the account's grants (below). |
 | `mcp.deny_system_schemas` | `ON` | No table access in `mysql` and `sys`. `information_schema` and `performance_schema` stay readable (the tools use them; grants govern them). |
 | `mcp.allowed_schemas` | empty | Comma-separated schemas whose tables MCP sessions may access; blank means all. A value with no names in it, such as `,`, allows none. Names are compared exactly, or case-insensitively when `lower_case_table_names` is 1 or 2. The system schemas above are governed by `mcp.deny_system_schemas`, and `mysql_mcp` is always allowed. |
+| `mcp.max_execution_time_ms` | 0 | Time limit for their `SELECT` statements, which they cannot raise; 0 turns the guard's limit off (the server's own `max_execution_time` default still applies) (below). |
+| `mcp.log_denials` | `ON` | Write refusals to the error log, at most 10 lines a minute (below). |
 
 `SET GLOBAL` and `SET PERSIST` of `mcp.*` need `MCP_ADMIN` on top of `SYSTEM_VARIABLES_ADMIN`. Persisted values load at startup as usual. Values given in `INSTALL COMPONENT ... SET` are taken from the installer.
 
@@ -64,6 +66,27 @@ Because of the double reading, a `SELECT` whose string literal contains a backsl
 
 `CALL` is allowed for any routine in the `mysql_mcp` schema, not only the tool pack's. Keep only the tool pack in `mysql_mcp` (it is installed and dropped as a whole).
 
+### Time limit (mcp.max_execution_time_ms)
+
+When an MCP session connects, the guard sets its session `max_execution_time` to `mcp.max_execution_time_ms`, so its `SELECT` statements stop after that many milliseconds (error 3024). The session may lower it, but not raise it. These are refused with error 1290 naming `mcp.max_execution_time_ms`:
+
+- `SET [SESSION] max_execution_time` (or `@@max_execution_time`) to 0, above the limit, or to anything but a literal (`DEFAULT`, an expression, a variable).
+- The optimizer hints `MAX_EXECUTION_TIME(n)` and `SET_VAR(max_execution_time = n)` with such a value.
+
+A changed limit reaches connected MCP sessions at their next statement, and the limit is applied again after `COM_CHANGE_USER` and `COM_RESET_CONNECTION`, which reset session variables. Setting it back to 0 leaves their current session value as it is.
+
+As with the server's own `max_execution_time`, the limit covers top-level read-only `SELECT` statements. MySQL ignores it inside stored programs, so **`CALL mysql_mcp.*` tool-pack calls are not limited**. Those run catalog queries on `information_schema`. If they must be limited too, revoke `EXECUTE` on `mysql_mcp` from the MCP account: mysql-mcp-server then falls back to its own SQL, whose `SELECT`s the limit covers.
+
+### Error log (mcp.log_denials)
+
+Each refusal is written as a warning, with the setting, the connection id and the start of the statement (up to 256 bytes, string literals replaced by `'?'`, line breaks by spaces) or the table:
+
+```
+[Warning] [MY-011071] [mcp_guard] mcp_guard: refused by mcp.read_only: MCP connection 11: INSERT INTO d.t VALUES (1)
+```
+
+At most 10 lines are written per minute; the number left out is reported with the next line after the minute. String literals are redacted, but numbers and identifiers are kept; turn `mcp.log_denials` off if even those must not reach the error log.
+
 ### Errors
 
 A denial fails the statement with error **1290** (`ER_OPTION_PREVENTS_STATEMENT`), the server's own `read_only` error, naming the setting:
@@ -87,8 +110,8 @@ The option is `mcp.read_only`, `mcp.deny_system_schemas`, `mcp.allowed_schemas`
 
 - `mcp.allowed_schemas` limits **table access**, not catalog metadata: `information_schema` and `SHOW` still list what the account's grants allow.
 - With `mcp.deny_system_schemas = ON`, mysql-mcp-server's opt-in `slow_query_log` tool (which reads `mysql.slow_log`) is denied.
-- Planned (RFC 0001): a `mcp.max_execution_time_ms` floor, denials in the error log and audit log, `performance_schema.mcp_tool_calls`.
+- Planned (RFC 0001 Phase 3): denials in the audit log, `performance_schema.mcp_tool_calls`.
 
 ### Tests
 
-`scripts/test-mcp-guard.sh <mysql-tag> <artifact-dir>` runs install, restart, persistence, uninstall and the enforcement cases against the official image (65 checks, including a `lower_case_table_names=1` server), and `src/mcp/guard/test_mcp_guard_policy.cc` unit-tests the classification and the SQL scanner. CI (`integration-scripts.yml`, job `mcp-guard`) runs both on MySQL 8.4.11, 9.7.2 and 26.10.0.
+`scripts/test-mcp-guard.sh <mysql-tag> <artifact-dir>` runs install, restart, persistence, uninstall and the enforcement cases against the official image (80 checks, including a `lower_case_table_names=1` server), and `src/mcp/guard/test_mcp_guard_policy.cc` unit-tests the classification and the SQL scanner. CI (`integration-scripts.yml`, job `mcp-guard`) runs both on MySQL 8.4.11, 9.7.2 and 26.10.0.

scripts/test-mcp-guard.sh

@@ -144,6 +144,45 @@ expect "mcp.enabled ON again" "$(mcp "SELECT 1")" "^1$"
 
 expect "invalid value rejected" "$(sql "SET GLOBAL mcp.read_only = 'maybe'")" "ERROR"
 
+# --- mcp.max_execution_time_ms: a time limit MCP sessions cannot raise ------------------------
+expect "SET GLOBAL mcp.max_execution_time_ms = 1000" "$(sql "SET GLOBAL mcp.max_execution_time_ms = 1000")" "^$"
+expect "mcp: session max_execution_time set at connect" "$(mcp "SELECT @@max_execution_time")" "^1000$"
+expect "mcp: lowering it is allowed" "$(mcp "SET SESSION max_execution_time = 500; SELECT @@max_execution_time")" "^500$"
+denied "mcp: SET max_execution_time = 0" "$(mcp "SET SESSION max_execution_time = 0")" "mcp.max_execution_time_ms"
+denied "mcp: SET max_execution_time above the limit" "$(mcp "SET @@max_execution_time = 5000")" "mcp.max_execution_time_ms"
+denied "mcp: MAX_EXECUTION_TIME(0) hint" "$(mcp "SELECT /*+ MAX_EXECUTION_TIME(0) */ COUNT(*) FROM d1.t")" "mcp.max_execution_time_ms"
+denied "mcp: SET_VAR(max_execution_time=0) hint" "$(mcp "SELECT /*+ SET_VAR(max_execution_time=0) */ COUNT(*) FROM d1.t")" "mcp.max_execution_time_ms"
+start=$(date +%s)
+slept=$(mcp "SELECT SLEEP(5) FROM d1.t")
+took=$(($(date +%s) - start))
+# Interrupted by the time limit: SLEEP() alone returns 1; reading a table, as here, the
+# statement fails with 3024 (ER_QUERY_TIMEOUT). Either way it must not run 5s.
+if [ "$took" -le 3 ] && { [ "$slept" = 1 ] || printf '%s' "$slept" | grep -q '^ERROR 3024 '; }; then ok "mcp: a 5s SELECT is stopped by the 1s limit (${took}s)"; else bad "mcp: time limit enforced" "took ${took}s, result '$slept'"; fi
+expect "app (no MCP_USER) keeps max_execution_time 0" "$(as app apppass1 "SELECT @@max_execution_time")" "^0$"
+sql "SET GLOBAL mcp.max_execution_time_ms = 0" >/dev/null
+expect "mcp: no limit once the floor is 0" "$(mcp "SELECT @@max_execution_time")" "^0$"
+# A session already connected gets a new limit at its next statement.
+mcp "SELECT @@max_execution_time; DO SLEEP(3); SELECT @@max_execution_time" >"/tmp/$CNAME-live" 2>&1 &
+live=$!
+sleep 1
+sql "SET GLOBAL mcp.max_execution_time_ms = 1500" >/dev/null
+wait "$live"
+expect "mcp: an existing session gets a tightened limit" "$(tr '\n' ' ' <"/tmp/$CNAME-live")" "^0 1500 $"
+rm -f "/tmp/$CNAME-live"
+sql "SET GLOBAL mcp.max_execution_time_ms = 0" >/dev/null
+
+# --- mcp.log_denials -----------------------------------------------------------------------------
+expect "refusals are written to the error log" "$(docker logs "$CNAME" 2>&1 | grep 'mcp_guard: refused by' | tail -3)" '\[MY-011071\] \[mcp_guard\] mcp_guard: refused by mcp\.(read_only|max_execution_time_ms): MCP connection [0-9]+'
+mcp "SELECT 'token=hunter2' FROM d1.t FOR UPDATE" >/dev/null
+mcp "SET SESSION sql_mode = 'NO_BACKSLASH_ESCAPES'; SELECT 'a\\', 'token=hunter2' FROM d1.t FOR UPDATE" >/dev/null
+expect "error log redacts string literals" "$(docker logs "$CNAME" 2>&1 | grep 'mcp_guard: refused by' | grep -c 'hunter2')" "^0$"
+sql "SET GLOBAL mcp.log_denials = OFF" >/dev/null
+before=$(docker logs "$CNAME" 2>&1 | grep -c 'mcp_guard: refused by')
+mcp "INSERT INTO d1.t VALUES (8)" >/dev/null
+after=$(docker logs "$CNAME" 2>&1 | grep -c 'mcp_guard: refused by')
+expect "mcp.log_denials = OFF writes nothing" "$after" "^$before$"
+sql "SET GLOBAL mcp.log_denials = ON" >/dev/null
+
 status=$(sql "SHOW GLOBAL STATUS LIKE 'mcp.%'")
 expect "status: statements_denied counted" "$status" "mcp.statements_denied	[1-9]"
 expect "status: table_access_denied counted" "$status" "mcp.table_access_denied	[1-9]"
@@ -179,6 +218,9 @@ CREATE USER mcp@'%' IDENTIFIED BY 'mcppass1'; GRANT SELECT ON *.* TO mcp@'%'; GR
 	expect "lower_case_table_names=1: SET GLOBAL mcp.allowed_schemas = 'Shop'" "$(sql "SET GLOBAL mcp.allowed_schemas = 'Shop'")" "^$"
 	expect "lower_case_table_names=1: allowed_schemas 'Shop' allows shop" "$(mcp "SELECT COUNT(*) FROM Shop.t")" "^0$"
 	denied "lower_case_table_names=1: other schemas still denied" "$(mcp "SELECT COUNT(*) FROM other.t")" "mcp.allowed_schemas"
+	# A fresh server: its first minute of refusals is logged up to 10 lines, then held back.
+	for _ in $(seq 1 15); do mcp "SELECT COUNT(*) FROM other.t" >/dev/null; done
+	expect "error log rate limit: 16 refusals in a minute, 10 lines" "$(docker logs "$CNAME" 2>&1 | grep -c 'mcp_guard: refused by')" "^10$"
 else
 	bad "lower_case_table_names=1 server" "did not start"
 fi