fix(mcp): report request timing and transport failures

Signed-off-by: lorenzozanee <wyz0707@proton.me>
This commit is contained in:
lorenzozanee committed 2026-09-27 01:34:35 +08:00
1 parent 64c23fab6c
commit 6f17caa7a7
7 files changed
+439 -104

No files matched your search

+17 -4
View File
@@ -2144,13 +2144,19 @@ static void application_update_notice_inject(cbm_daemon_application_session_t *s
char **response_io) {
cbm_daemon_application_t *application = session->application;
cbm_mutex_lock(&application->mutex);
if (session->background_eligible && !session->update_notice_delivered &&
!session->pending_update_notice && application->update_thread_done &&
application->update_notice[0] &&
cbm_mcp_jsonrpc_response_prepend_notice(response_io, application->update_notice)) {
bool should_inject = session->background_eligible && !session->update_notice_delivered &&
!session->pending_update_notice && application->update_thread_done &&
application->update_notice[0];
bool injected = should_inject &&
cbm_mcp_jsonrpc_response_prepend_notice(response_io,
application->update_notice);
if (injected) {
session->pending_update_notice = true;
}
cbm_mutex_unlock(&application->mutex);
if (should_inject && !injected) {
cbm_log_warn("daemon.update_notice.inject_failed", "status", "omitted");
}
}
static bool application_watch_job_subscription_exists_locked(
@@ -2556,6 +2562,13 @@ static cbm_daemon_runtime_application_status_t application_mcp_request(
parsed_ok && parsed.has_id && parsed.method && strcmp(parsed.method, "tools/call") == 0;
char *response = cbm_mcp_server_handle(session->mcp, message);
free(message);
if (!response && (!parsed_ok || parsed.has_id)) {
cbm_log_error("daemon.mcp.response_missing", "status", "error");
if (parsed_ok) {
cbm_jsonrpc_request_free(&parsed);
}
return CBM_DAEMON_RUNTIME_APPLICATION_HANDLER_ERROR;
}
if (initialize_request && application_jsonrpc_success(response)) {
cbm_mutex_lock(&session->application->mutex);
session->pending_background_initialize = true;
+17 -5
View File
@@ -363,17 +363,29 @@ static void copy_path_without_query(const char *path, char *out, size_t outsz) {
}
void cbm_log_mcp_request(const char *method, const char *tool_name, bool is_error,
int64_t duration_us) {
int64_t duration_us, int64_t handler_duration_us,
int64_t response_serialization_us, bool cancelled, bool timed_out) {
char duration_ms[CBM_SZ_32];
char handler_duration_ms[CBM_SZ_32];
char response_serialization_ms[CBM_SZ_32];
snprintf(duration_ms, sizeof(duration_ms), "%" PRId64, duration_us / 1000);
snprintf(handler_duration_ms, sizeof(handler_duration_ms), "%" PRId64,
handler_duration_us / 1000);
snprintf(response_serialization_ms, sizeof(response_serialization_ms), "%" PRId64,
response_serialization_us / 1000);
const char *status = timed_out ? "timeout" : (is_error ? "error" : "ok");
if (tool_name && tool_name[0] != '\0') {
cbm_log(is_error ? CBM_LOG_WARN : CBM_LOG_INFO, "mcp.request", "protocol", "jsonrpc",
"method", method ? method : "", "tool", tool_name, "status",
is_error ? "error" : "ok", "duration_ms", duration_ms, NULL);
"method", method ? method : "", "tool", tool_name, "status", status,
"duration_ms", duration_ms, "handler_duration_ms", handler_duration_ms,
"response_serialization_ms", response_serialization_ms, "cancelled",
cancelled ? "true" : "false", "timed_out", timed_out ? "true" : "false", NULL);
} else {
cbm_log(is_error ? CBM_LOG_WARN : CBM_LOG_INFO, "mcp.request", "protocol", "jsonrpc",
"method", method ? method : "", "status", is_error ? "error" : "ok", "duration_ms",
duration_ms, NULL);
"method", method ? method : "", "status", status, "duration_ms", duration_ms,
"handler_duration_ms", handler_duration_ms, "response_serialization_ms",
response_serialization_ms, "cancelled", cancelled ? "true" : "false", "timed_out",
timed_out ? "true" : "false", NULL);
}
}
+2 -1
View File
@@ -95,7 +95,8 @@ void cbm_log_int(CBMLogLevel level, const char *msg, const char *key, int64_t va
/* Operational event helpers. They deliberately avoid request bodies, headers,
* arguments, and query strings. */
void cbm_log_mcp_request(const char *method, const char *tool_name, bool is_error,
int64_t duration_us);
int64_t duration_us, int64_t handler_duration_us,
int64_t response_serialization_us, bool cancelled, bool timed_out);
void cbm_log_http_request(const char *component, const char *method, const char *path, int status,
int64_t duration_ms, size_t request_bytes, size_t response_bytes);
+223 -79
View File
@@ -128,6 +128,7 @@ enum {
/* JSON-RPC 2.0 standard error codes */
#define JSONRPC_PARSE_ERROR (-32700)
#define MCP_INPUT_CLOSED (-2)
#define JSONRPC_METHOD_NOT_FOUND (-32601)
#define JSONRPC_INVALID_PARAMS (-32602)
#define JSONRPC_INTERNAL_ERROR (-32603)
@@ -245,28 +246,45 @@ int cbm_jsonrpc_parse(const char *line, cbm_jsonrpc_request_t *out) {
yyjson_val *v_id = yyjson_obj_get(root, "id");
yyjson_val *v_params = yyjson_obj_get(root, "params");
if (!v_method || !yyjson_is_str(v_method)) {
if (!v_jsonrpc || !yyjson_is_str(v_jsonrpc) ||
strcmp(yyjson_get_str(v_jsonrpc), "2.0") != 0 || !v_method ||
!yyjson_is_str(v_method) ||
(v_id && !yyjson_is_int(v_id) && !yyjson_is_str(v_id))) {
yyjson_doc_free(doc);
return CBM_NOT_FOUND;
}
out->jsonrpc =
heap_strdup(v_jsonrpc && yyjson_is_str(v_jsonrpc) ? yyjson_get_str(v_jsonrpc) : "2.0");
out->jsonrpc = heap_strdup(yyjson_get_str(v_jsonrpc));
out->method = heap_strdup(yyjson_get_str(v_method));
if (!out->jsonrpc || !out->method) {
yyjson_doc_free(doc);
cbm_jsonrpc_request_free(out);
return CBM_NOT_FOUND;
}
if (v_id) {
out->has_id = true;
if (yyjson_is_int(v_id)) {
out->id = yyjson_get_int(v_id);
} else if (yyjson_is_str(v_id)) {
} else {
/* JSON-RPC 2.0 §4 permits string ids (Claude Desktop uses them).
* Preserve verbatim instead of coercing via strtol (issue #253). */
out->id_str = heap_strdup(yyjson_get_str(v_id));
if (!out->id_str) {
yyjson_doc_free(doc);
cbm_jsonrpc_request_free(out);
return CBM_NOT_FOUND;
}
}
}
if (v_params) {
out->params_raw = yyjson_val_write(v_params, 0, NULL);
if (!out->params_raw) {
yyjson_doc_free(doc);
cbm_jsonrpc_request_free(out);
return CBM_NOT_FOUND;
}
}
yyjson_doc_free(doc);
@@ -289,36 +307,62 @@ void cbm_jsonrpc_request_free(cbm_jsonrpc_request_t *r) {
* ══════════════════════════════════════════════════════════════════ */
char *cbm_jsonrpc_format_response(const cbm_jsonrpc_response_t *resp) {
if (!resp) {
return NULL;
}
yyjson_mut_doc *doc = yyjson_mut_doc_new(NULL);
if (!doc) {
return NULL;
}
yyjson_mut_val *root = yyjson_mut_obj(doc);
if (!root) {
yyjson_mut_doc_free(doc);
return NULL;
}
yyjson_mut_doc_set_root(doc, root);
yyjson_mut_obj_add_str(doc, root, "jsonrpc", "2.0");
bool added = yyjson_mut_obj_add_str(doc, root, "jsonrpc", "2.0");
if (resp->id_str) {
yyjson_mut_obj_add_str(doc, root, "id", resp->id_str);
added = added && yyjson_mut_obj_add_str(doc, root, "id", resp->id_str);
} else {
yyjson_mut_obj_add_int(doc, root, "id", resp->id);
added = added && yyjson_mut_obj_add_int(doc, root, "id", resp->id);
}
if (!added) {
yyjson_mut_doc_free(doc);
return NULL;
}
if (resp->error_json) {
/* Parse the error JSON and embed */
yyjson_doc *err_doc = yyjson_read(resp->error_json, strlen(resp->error_json), 0);
if (err_doc) {
yyjson_mut_val *err_val = yyjson_val_mut_copy(doc, yyjson_doc_get_root(err_doc));
yyjson_mut_obj_add_val(doc, root, "error", err_val);
yyjson_doc_free(err_doc);
if (!err_doc) {
yyjson_mut_doc_free(doc);
return NULL;
}
yyjson_mut_val *err_val = yyjson_val_mut_copy(doc, yyjson_doc_get_root(err_doc));
bool added = err_val && yyjson_mut_obj_add_val(doc, root, "error", err_val);
yyjson_doc_free(err_doc);
if (!added) {
yyjson_mut_doc_free(doc);
return NULL;
}
} else if (resp->result_json) {
/* Parse the result JSON and embed */
yyjson_doc *res_doc = yyjson_read(resp->result_json, strlen(resp->result_json), 0);
if (res_doc) {
yyjson_mut_val *res_val = yyjson_val_mut_copy(doc, yyjson_doc_get_root(res_doc));
yyjson_mut_obj_add_val(doc, root, "result", res_val);
yyjson_doc_free(res_doc);
if (!res_doc) {
yyjson_mut_doc_free(doc);
return NULL;
}
yyjson_mut_val *res_val = yyjson_val_mut_copy(doc, yyjson_doc_get_root(res_doc));
bool added = res_val && yyjson_mut_obj_add_val(doc, root, "result", res_val);
yyjson_doc_free(res_doc);
if (!added) {
yyjson_mut_doc_free(doc);
return NULL;
}
} else {
/* JSON-RPC 2.0 spec: response MUST contain "result" or "error" */
yyjson_mut_obj_add_null(doc, root, "result");
yyjson_mut_doc_free(doc);
return NULL;
}
char *out = yy_final_doc_to_str(doc);
@@ -326,13 +370,44 @@ char *cbm_jsonrpc_format_response(const cbm_jsonrpc_response_t *resp) {
return out;
}
static char *mcp_format_response_or_error(const cbm_jsonrpc_response_t *resp,
bool *serialization_failed) {
if (serialization_failed) {
*serialization_failed = false;
}
char *formatted = cbm_jsonrpc_format_response(resp);
if (formatted) {
return formatted;
}
if (serialization_failed) {
*serialization_failed = true;
}
cbm_jsonrpc_response_t error_resp = {
.id = resp->id,
.id_str = resp->id_str,
.error_json = "{\"code\":-32603,\"message\":\"Failed to serialize the server response\"}",
};
return cbm_jsonrpc_format_response(&error_resp);
}
char *cbm_jsonrpc_format_error(int64_t id, int code, const char *message) {
yyjson_mut_doc *doc = yyjson_mut_doc_new(NULL);
if (!doc) {
return NULL;
}
yyjson_mut_val *root = yyjson_mut_obj(doc);
if (!root) {
yyjson_mut_doc_free(doc);
return NULL;
}
yyjson_mut_doc_set_root(doc, root);
yyjson_mut_obj_add_str(doc, root, "jsonrpc", "2.0");
yyjson_mut_obj_add_int(doc, root, "id", id);
bool added = yyjson_mut_obj_add_str(doc, root, "jsonrpc", "2.0");
added = added && yyjson_mut_obj_add_int(doc, root, "id", id);
if (!added) {
yyjson_mut_doc_free(doc);
return NULL;
}
char *encoded_message = NULL;
size_t encoded_message_len = 0;
@@ -340,13 +415,21 @@ char *cbm_jsonrpc_format_error(int64_t id, int code, const char *message) {
if (!cbm_output_encode_text(raw_message, strlen(raw_message), &encoded_message,
&encoded_message_len)) {
yyjson_mut_doc_free(doc);
free(encoded_message);
return NULL;
}
yyjson_mut_val *err = yyjson_mut_obj(doc);
yyjson_mut_obj_add_int(doc, err, "code", code);
yyjson_mut_obj_add_str(doc, err, "message", encoded_message ? encoded_message : raw_message);
yyjson_mut_obj_add_val(doc, root, "error", err);
added = err && yyjson_mut_obj_add_int(doc, err, "code", code);
added = added &&
yyjson_mut_obj_add_str(doc, err, "message", encoded_message ? encoded_message
: raw_message);
added = added && yyjson_mut_obj_add_val(doc, root, "error", err);
if (!added) {
yyjson_mut_doc_free(doc);
free(encoded_message);
return NULL;
}
char *out = yy_final_doc_to_str(doc);
yyjson_mut_doc_free(doc);
@@ -2933,7 +3016,9 @@ static char *handle_list_projects(cbm_mcp_server_t *srv, const char *args) {
free(records);
return cbm_mcp_text_result("out of memory while listing projects", true);
}
qsort(records, (size_t)record_count, sizeof(*records), project_record_compare);
if (record_count > 1) {
qsort(records, (size_t)record_count, sizeof(*records), project_record_compare);
}
int limit = cbm_mcp_get_int_arg(args, "limit", 50);
int offset = cbm_mcp_get_int_arg(args, "offset", 0);
@@ -17796,6 +17881,11 @@ bool cbm_mcp_jsonrpc_response_prepend_notice(char **response_io, const char *not
return true;
}
static long long mcp_elapsed_us(struct timespec start, struct timespec end) {
return ((long long)(end.tv_sec - start.tv_sec) * MCP_S_TO_US) +
((long long)(end.tv_nsec - start.tv_nsec) / MCP_MS_TO_US);
}
char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
cbm_jsonrpc_request_t req = {0};
if (cbm_jsonrpc_parse(line, &req) < 0) {
@@ -17826,7 +17916,11 @@ char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
cbm_clock_gettime(CLOCK_MONOTONIC, &req_t0);
char *result_json = NULL;
char *request_error_json = NULL;
bool request_logged = false;
char *request_tool_name = NULL;
long long handler_duration_us = 0;
bool request_is_error = false;
bool request_cancelled = false;
bool request_timed_out = false;
if (strcmp(req.method, "initialize") == 0) {
result_json = cbm_mcp_initialize_response_for_profile(req.params_raw, srv->tool_profile);
@@ -17853,6 +17947,7 @@ char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
char *tool_name = req.params_raw ? cbm_mcp_get_tool_name(req.params_raw) : NULL;
char *tool_args =
req.params_raw ? cbm_mcp_get_arguments(req.params_raw) : heap_strdup("{}");
request_tool_name = tool_name;
srv->active_request_id = req.id;
free(srv->active_request_id_str);
srv->active_request_id_str = req.id_str ? heap_strdup(req.id_str) : NULL;
@@ -17865,16 +17960,15 @@ char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
srv->active_request_id_str = NULL;
struct timespec t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &t1);
long long dur_us = ((long long)(t1.tv_sec - t0.tv_sec) * MCP_S_TO_US) +
((long long)(t1.tv_nsec - t0.tv_nsec) / MCP_MS_TO_US);
long long dur_us = mcp_elapsed_us(t0, t1);
bool is_err = (result_json != NULL) && (strstr(result_json, "\"isError\":true") != NULL);
cbm_diag_record_query(dur_us, is_err);
long long request_dur_us = ((long long)(t1.tv_sec - req_t0.tv_sec) * MCP_S_TO_US) +
((long long)(t1.tv_nsec - req_t0.tv_nsec) / MCP_MS_TO_US);
cbm_log_mcp_request(req.method, tool_name, is_err, request_dur_us);
request_logged = true;
handler_duration_us = mcp_elapsed_us(req_t0, t1);
request_is_error = is_err;
request_cancelled = mcp_request_cancelled(srv);
request_timed_out = result_json &&
strstr(result_json, "\"code\":\"request_timeout\"") != NULL;
free(tool_name);
free(tool_args);
} else {
/* Echo the original id (string or numeric, issue #253) on the error. */
@@ -17886,12 +17980,18 @@ char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
.id_str = req.id_str,
.error_json = err_obj,
};
char *err = cbm_jsonrpc_format_response(&err_resp);
struct timespec t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &t1);
long long dur_us = ((long long)(t1.tv_sec - req_t0.tv_sec) * MCP_S_TO_US) +
((long long)(t1.tv_nsec - req_t0.tv_nsec) / MCP_MS_TO_US);
cbm_log_mcp_request(req.method, NULL, true, dur_us);
long long handler_us = mcp_elapsed_us(req_t0, t1);
struct timespec serialize_t0;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t0);
char *err = mcp_format_response_or_error(&err_resp, NULL);
struct timespec serialize_t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t1);
long long serialization_us = mcp_elapsed_us(serialize_t0, serialize_t1);
long long duration_us = mcp_elapsed_us(req_t0, serialize_t1);
cbm_log_mcp_request(req.method, NULL, true, duration_us, handler_us, serialization_us,
false, false);
cbm_mcp_server_request_scope_end(srv);
cbm_jsonrpc_request_free(&req);
return err;
@@ -17903,32 +18003,43 @@ char *cbm_mcp_server_handle(cbm_mcp_server_t *srv, const char *line) {
.id_str = req.id_str,
.error_json = request_error_json,
};
char *err = cbm_jsonrpc_format_response(&err_resp);
struct timespec t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &t1);
long long dur_us = ((long long)(t1.tv_sec - req_t0.tv_sec) * MCP_S_TO_US) +
((long long)(t1.tv_nsec - req_t0.tv_nsec) / MCP_MS_TO_US);
cbm_log_mcp_request(req.method, NULL, true, dur_us);
struct timespec serialize_t0;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t0);
char *err = mcp_format_response_or_error(&err_resp, NULL);
struct timespec serialize_t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t1);
long long handler_us = mcp_elapsed_us(req_t0, serialize_t0);
long long serialization_us = mcp_elapsed_us(serialize_t0, serialize_t1);
long long duration_us = mcp_elapsed_us(req_t0, serialize_t1);
cbm_log_mcp_request(req.method, NULL, true, duration_us, handler_us, serialization_us,
false, false);
free(request_error_json);
cbm_mcp_server_request_scope_end(srv);
cbm_jsonrpc_request_free(&req);
return err;
}
if (!request_logged) {
struct timespec t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &t1);
long long dur_us = ((long long)(t1.tv_sec - req_t0.tv_sec) * MCP_S_TO_US) +
((long long)(t1.tv_nsec - req_t0.tv_nsec) / MCP_MS_TO_US);
cbm_log_mcp_request(req.method, NULL, false, dur_us);
}
cbm_jsonrpc_response_t resp = {
.id = req.id,
.id_str = req.id_str,
.result_json = result_json,
};
char *out = cbm_jsonrpc_format_response(&resp);
struct timespec serialize_t0;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t0);
bool serialization_failed = false;
char *out = mcp_format_response_or_error(&resp, &serialization_failed);
struct timespec serialize_t1;
cbm_clock_gettime(CLOCK_MONOTONIC, &serialize_t1);
long long serialization_us = mcp_elapsed_us(serialize_t0, serialize_t1);
long long duration_us = mcp_elapsed_us(req_t0, serialize_t1);
request_is_error = request_is_error || serialization_failed || out == NULL;
if (!request_tool_name) {
handler_duration_us = duration_us - serialization_us;
}
cbm_log_mcp_request(req.method, request_tool_name, request_is_error, duration_us,
handler_duration_us, serialization_us, request_cancelled,
request_timed_out);
free(request_tool_name);
free(result_json);
cbm_mcp_server_request_scope_end(srv);
cbm_jsonrpc_request_free(&req);
@@ -18123,8 +18234,7 @@ int cbm_mcp_read_message(FILE *in, char **message, bool *content_length_framed)
}
#ifndef _WIN32
/* Unix 3-phase poll: non-blocking fd check, FILE* buffer peek, blocking poll.
* Returns: 1 = data ready, 0 = timeout (evicted idle stores), -1 = error/EOF. */
/* Unix 3-phase poll: non-blocking fd check, FILE* buffer peek, blocking poll. */
static int poll_for_input_unix(cbm_mcp_server_t *srv, int fd, FILE *in) {
struct pollfd pfd = {.fd = fd, .events = POLLIN};
int pr = poll(&pfd, SKIP_ONE, 0); /* Phase 1: non-blocking */
@@ -18139,26 +18249,28 @@ static int poll_for_input_unix(cbm_mcp_server_t *srv, int fd, FILE *in) {
/* Phase 2: peek FILE* buffer */
int saved_flags = fcntl(fd, F_GETFL);
if (saved_flags < 0) {
/* fcntl failed — fall through to a short blocking poll (see the Phase-3
* note below on why the interval is bounded, not the full idle timeout) */
pr = poll(&pfd, SKIP_ONE, MCP_TIMEOUT_MS);
if (pr < 0) {
return CBM_NOT_FOUND;
}
if (pr == 0) {
cbm_mcp_server_evict_idle(srv, STORE_IDLE_TIMEOUT_S);
return 0;
}
return SKIP_ONE;
return CBM_NOT_FOUND;
}
(void)fcntl(fd, F_SETFL, saved_flags | O_NONBLOCK);
if (fcntl(fd, F_SETFL, saved_flags | O_NONBLOCK) < 0) {
return CBM_NOT_FOUND;
}
errno = 0;
int c = fgetc(in);
(void)fcntl(fd, F_SETFL, saved_flags);
int read_errno = errno;
bool read_failed = ferror(in) != 0;
bool reached_eof = feof(in) != 0;
int restore_result = fcntl(fd, F_SETFL, saved_flags);
if (restore_result < 0) {
return CBM_NOT_FOUND;
}
if (c == EOF) {
if (feof(in)) {
return CBM_NOT_FOUND; /* true EOF */
if (reached_eof) {
return MCP_INPUT_CLOSED;
}
if (!read_failed || (read_errno != EAGAIN && read_errno != EWOULDBLOCK)) {
return CBM_NOT_FOUND;
}
clearerr(in);
/* Phase 3: blocking poll, bounded to a SHORT interval (not the full idle
@@ -18180,7 +18292,9 @@ static int poll_for_input_unix(cbm_mcp_server_t *srv, int fd, FILE *in) {
return SKIP_ONE;
}
(void)ungetc(c, in);
if (ungetc(c, in) == EOF) {
return CBM_NOT_FOUND;
}
return SKIP_ONE;
}
#endif
@@ -18221,7 +18335,8 @@ int cbm_mcp_server_run(cbm_mcp_server_t *srv, FILE *in, FILE *out) {
HANDLE hStdin = (HANDLE)_get_osfhandle(fd);
DWORD wr = WaitForSingleObject(hStdin, STORE_IDLE_TIMEOUT_S * MCP_TIMEOUT_MS);
if (wr == WAIT_FAILED) {
break;
cbm_log_error("mcp.input.poll", "status", "error");
return 1;
}
if (wr == WAIT_TIMEOUT) {
cbm_mcp_server_evict_idle(srv, STORE_IDLE_TIMEOUT_S);
@@ -18229,9 +18344,13 @@ int cbm_mcp_server_run(cbm_mcp_server_t *srv, FILE *in, FILE *out) {
}
#else
int pr = poll_for_input_unix(srv, fd, in);
if (pr < 0) {
if (pr == MCP_INPUT_CLOSED) {
break;
}
if (pr < 0) {
cbm_log_error("mcp.input.poll", "status", "error");
return 1;
}
if (pr == 0) {
continue; /* timeout — idle stores evicted */
}
@@ -18239,21 +18358,46 @@ int cbm_mcp_server_run(cbm_mcp_server_t *srv, FILE *in, FILE *out) {
char *message = NULL;
bool content_length_framed = false;
if (cbm_mcp_read_message(in, &message, &content_length_framed) <= 0) {
int read_status = cbm_mcp_read_message(in, &message, &content_length_framed);
if (read_status == 0) {
break;
}
if (read_status < 0) {
cbm_log_error("mcp.request.read", "status", "error");
return 1;
}
char *resp = cbm_mcp_server_handle(srv, message);
bool notification = false;
if (!resp) {
cbm_jsonrpc_request_t request = {0};
notification = cbm_jsonrpc_parse(message, &request) == 0 && !request.has_id;
cbm_jsonrpc_request_free(&request);
}
free(message);
if (resp) {
if (content_length_framed) {
size_t response_len = strlen(resp);
(void)fprintf(out, "Content-Length: %zu\r\n\r\n%s", response_len, resp);
} else {
(void)fprintf(out, "%s\n", resp);
if (!resp) {
if (!notification) {
cbm_log_error("mcp.response.missing", "protocol", "jsonrpc", "status", "error");
return 1;
}
(void)fflush(out);
free(resp);
continue;
}
int write_result;
if (content_length_framed) {
size_t response_len = strlen(resp);
write_result = fprintf(out, "Content-Length: %zu\r\n\r\n%s", response_len, resp);
} else {
write_result = fprintf(out, "%s\n", resp);
}
free(resp);
if (write_result < 0) {
cbm_log_error("mcp.response.write", "protocol", "jsonrpc", "stage", "write");
return 1;
}
if (fflush(out) != 0) {
cbm_log_error("mcp.response.write", "protocol", "jsonrpc", "stage", "flush");
return 1;
}
}
+24 -1
View File
@@ -1803,7 +1803,30 @@ static void handle_rpc(cbm_http_conn_t *c, const cbm_http_req_t *req, cbm_mcp_se
cbm_http_replyf(c, 200, g_cors_json, "%s", response);
free(response);
} else {
cbm_http_replyf(c, 204, g_cors, "%s", "");
cbm_jsonrpc_request_t parsed = {0};
bool parsed_ok = cbm_jsonrpc_parse(req->body, &parsed) == 0;
bool notification = parsed_ok && !parsed.has_id;
char *error_response = NULL;
if (parsed_ok && parsed.has_id) {
cbm_jsonrpc_response_t error = {
.id = parsed.id,
.id_str = parsed.id_str,
.error_json = "{\"code\":-32603,\"message\":\"Failed to produce a response\"}",
};
error_response = cbm_jsonrpc_format_response(&error);
}
cbm_jsonrpc_request_free(&parsed);
if (notification) {
cbm_http_replyf(c, 204, g_cors, "%s", "");
} else {
cbm_log_error("http.rpc.response_missing", "status", "error");
if (error_response) {
cbm_http_replyf(c, 500, g_cors_json, "%s", error_response);
} else {
cbm_http_replyf(c, 500, g_cors, "%s", "Failed to produce a response");
}
}
free(error_response);
}
}
-5
View File
@@ -207,15 +207,10 @@ TEST(log_operational_helpers) {
cbm_log_set_level(CBM_LOG_DEBUG);
cbm_log_set_format(CBM_LOG_FORMAT_TEXT);
capture_start();
cbm_log_mcp_request("tools/call", "search_graph", false, 1250);
cbm_log_http_request("graph_ui", "GET", "/api/layout", 200, 7, 0, 42);
const char *output = capture_end();
cbm_log_set_level(CBM_LOG_INFO);
ASSERT(cbm_str_contains_raw(output, "msg=mcp.request"));
ASSERT(cbm_str_contains_raw(output, "protocol=jsonrpc"));
ASSERT(cbm_str_contains_raw(output, "method=tools/call"));
ASSERT(cbm_str_contains_raw(output, "tool=search_graph"));
ASSERT(cbm_str_contains_raw(output, "msg=http.request"));
ASSERT(cbm_str_contains_raw(output, "method=GET"));
ASSERT(cbm_str_contains_raw(output, "path=/api/layout"));
+156 -9
View File
@@ -1149,6 +1149,19 @@ TEST(jsonrpc_format_response) {
PASS();
}
TEST(jsonrpc_format_response_rejects_missing_or_malformed_payload) {
cbm_jsonrpc_response_t resp = {.id = 2};
ASSERT_NULL(cbm_jsonrpc_format_response(&resp));
resp.result_json = "{broken";
ASSERT_NULL(cbm_jsonrpc_format_response(&resp));
resp.result_json = NULL;
resp.error_json = "{broken";
ASSERT_NULL(cbm_jsonrpc_format_response(&resp));
PASS();
}
TEST(jsonrpc_format_error) {
char *json = cbm_jsonrpc_format_error(5, -32600, "Invalid Request");
ASSERT_NOT_NULL(json);
@@ -2225,6 +2238,10 @@ TEST(server_handle_logs_request_without_params) {
ASSERT_NOT_NULL(strstr(mcp_log_buf, "protocol=jsonrpc"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "method=tools/list"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "status=ok"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "handler_duration_ms="));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "response_serialization_ms="));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "cancelled=false"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "timed_out=false"));
ASSERT_NULL(strstr(mcp_log_buf, "token"));
ASSERT_NULL(strstr(mcp_log_buf, "secret"));
PASS();
@@ -10665,14 +10682,27 @@ TEST(search_code_cancel_cleans_supervised_scan) {
};
cbm_mcp_server_set_command_test_hook(srv, mcp_search_command_hook_probe, &probe);
char *response =
cbm_mcp_handle_tool(srv, "search_code",
"{\"pattern\":\"HandleRequest\",\"project\":\"prefilter-search\","
"\"file_pattern\":\"*.go\"}");
mcp_log_buf[0] = '\0';
CBMLogLevel previous_level = cbm_log_get_level();
cbm_log_set_level(CBM_LOG_INFO);
cbm_log_set_sink_ex(mcp_capture_log, CBM_LOG_SINK_REPLACE);
char *response = cbm_mcp_server_handle(
srv, "{\"jsonrpc\":\"2.0\",\"id\":1,\"method\":\"tools/call\","
"\"params\":{\"name\":\"search_code\",\"arguments\":{\"pattern\":"
"\"HandleRequest\",\"project\":\"prefilter-search\",\"file_pattern\":"
"\"*.go\"}}}");
cbm_log_set_sink(NULL);
cbm_log_set_level(previous_level);
ASSERT_NOT_NULL(response);
ASSERT_TRUE(probe.cancel_accepted);
ASSERT_NOT_NULL(strstr(response, "cancelled"));
ASSERT_NOT_NULL(strstr(response, "\"isError\":true"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "msg=mcp.request"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "tool=search_code"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "cancelled=true"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "timed_out=false"));
ASSERT_NULL(strstr(mcp_log_buf, "HandleRequest"));
ASSERT_NULL(strstr(mcp_log_buf, "prefilter-search"));
char logs[640];
snprintf(logs, sizeof(logs), "%s/logs", cache.path);
@@ -10685,6 +10715,39 @@ TEST(search_code_cancel_cleans_supervised_scan) {
PASS();
}
TEST(server_handle_logs_timeout_without_query) {
char tmp[512], src_path[768], vendor_path[768];
cbm_mcp_server_t *srv = setup_prefilter_server(tmp, sizeof(tmp), src_path, sizeof(src_path),
vendor_path, sizeof(vendor_path));
ASSERT_NOT_NULL(srv);
cbm_mcp_server_set_search_scan_timeout_for_test(srv, 0, true);
mcp_log_buf[0] = '\0';
CBMLogLevel previous_level = cbm_log_get_level();
cbm_log_set_level(CBM_LOG_INFO);
cbm_log_set_sink_ex(mcp_capture_log, CBM_LOG_SINK_REPLACE);
char *response = cbm_mcp_server_handle(
srv, "{\"jsonrpc\":\"2.0\",\"id\":2,\"method\":\"tools/call\","
"\"params\":{\"name\":\"search_code\",\"arguments\":{\"pattern\":"
"\"HandleRequest\",\"project\":\"prefilter-search\"}}}");
cbm_log_set_sink(NULL);
cbm_log_set_level(previous_level);
ASSERT_NOT_NULL(response);
ASSERT_NOT_NULL(strstr(mcp_log_buf, "status=timeout"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "timed_out=true"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "cancelled=false"));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "handler_duration_ms="));
ASSERT_NOT_NULL(strstr(mcp_log_buf, "response_serialization_ms="));
ASSERT_NULL(strstr(mcp_log_buf, "HandleRequest"));
ASSERT_NULL(strstr(mcp_log_buf, "prefilter-search"));
free(response);
cbm_mcp_server_free(srv);
cleanup_prefilter_dir(tmp, src_path, vendor_path);
PASS();
}
TEST(search_code_output_limit_fails_closed_and_cleans_scan) {
mcp_search_cache_t cache;
ASSERT_TRUE(mcp_search_cache_open(&cache, "cbm-search-limit"));
@@ -16631,14 +16694,24 @@ TEST(jsonrpc_parse_empty_string) {
}
TEST(jsonrpc_parse_missing_jsonrpc_field) {
/* jsonrpc field absent — parser defaults to "2.0" if method present */
/* JSON-RPC requests must declare their protocol version. */
const char *line = "{\"id\":1,\"method\":\"initialize\",\"params\":{}}";
cbm_jsonrpc_request_t req = {0};
int rc = cbm_jsonrpc_parse(line, &req);
ASSERT_EQ(rc, 0);
ASSERT_STR_EQ(req.jsonrpc, "2.0");
ASSERT_STR_EQ(req.method, "initialize");
ASSERT_TRUE(req.has_id);
ASSERT_EQ(rc, -1);
cbm_jsonrpc_request_free(&req);
PASS();
}
TEST(jsonrpc_parse_rejects_invalid_version_and_id) {
cbm_jsonrpc_request_t req = {0};
ASSERT_EQ(cbm_jsonrpc_parse(
"{\"jsonrpc\":\"1.0\",\"id\":1,\"method\":\"ping\"}", &req),
-1);
cbm_jsonrpc_request_free(&req);
ASSERT_EQ(cbm_jsonrpc_parse(
"{\"jsonrpc\":\"2.0\",\"id\":null,\"method\":\"ping\"}", &req),
-1);
cbm_jsonrpc_request_free(&req);
PASS();
}
@@ -16967,6 +17040,75 @@ TEST(mcp_server_run_rapid_messages) {
fclose(in_fp);
PASS();
}
#ifdef __linux__
TEST(mcp_server_run_reports_output_failure) {
int fds[2];
ASSERT_EQ(pipe(fds), 0);
const char message[] = "{\"jsonrpc\":\"2.0\",\"id\":1,\"method\":\"tools/list\",\"params\":{}}\n";
ASSERT_EQ(write(fds[1], message, sizeof(message) - 1), (ssize_t)(sizeof(message) - 1));
close(fds[1]);
FILE *in_fp = fdopen(fds[0], "r");
FILE *out_fp = fopen("/dev/full", "w");
ASSERT_NOT_NULL(in_fp);
ASSERT_NOT_NULL(out_fp);
cbm_mcp_server_t *srv = cbm_mcp_server_new(NULL);
ASSERT_NOT_NULL(srv);
mcp_log_buf[0] = '\0';
CBMLogLevel previous_level = cbm_log_get_level();
cbm_log_set_level(CBM_LOG_ERROR);
cbm_log_set_sink_ex(mcp_capture_log, CBM_LOG_SINK_REPLACE);
int rc = cbm_mcp_server_run(srv, in_fp, out_fp);
cbm_log_set_sink(NULL);
cbm_log_set_level(previous_level);
bool output_error_logged = strstr(mcp_log_buf, "stage=write") != NULL ||
strstr(mcp_log_buf, "stage=flush") != NULL;
cbm_mcp_server_free(srv);
fclose(in_fp);
fclose(out_fp);
ASSERT_TRUE(rc != 0);
ASSERT_NOT_NULL(strstr(mcp_log_buf, "msg=mcp.response.write"));
ASSERT_TRUE(output_error_logged);
PASS();
}
TEST(mcp_server_run_reports_input_failure) {
FILE *in_fp = tmpfile();
FILE *out_fp = tmpfile();
ASSERT_NOT_NULL(in_fp);
ASSERT_NOT_NULL(out_fp);
ASSERT_TRUE(fputs("Content-Length: nope\r\n\r\n", in_fp) >= 0);
rewind(in_fp);
cbm_mcp_server_t *srv = cbm_mcp_server_new(NULL);
ASSERT_NOT_NULL(srv);
mcp_log_buf[0] = '\0';
CBMLogLevel previous_level = cbm_log_get_level();
cbm_log_set_level(CBM_LOG_ERROR);
cbm_log_set_sink_ex(mcp_capture_log, CBM_LOG_SINK_REPLACE);
int rc = cbm_mcp_server_run(srv, in_fp, out_fp);
cbm_log_set_sink(NULL);
cbm_log_set_level(previous_level);
cbm_mcp_server_free(srv);
fclose(in_fp);
fclose(out_fp);
ASSERT_TRUE(rc != 0);
ASSERT_NOT_NULL(strstr(mcp_log_buf, "msg=mcp.request.read"));
PASS();
}
#else
TEST(mcp_server_run_reports_output_failure) {
SKIP_PLATFORM("/dev/full is Linux-specific");
}
TEST(mcp_server_run_reports_input_failure) {
SKIP_PLATFORM("tmpfile poll behavior is Unix-specific");
}
#endif
#endif /* !_WIN32 */
/* Issue #235: passing an unrecognised project name to a tool crashed the
@@ -20428,6 +20570,7 @@ SUITE(mcp) {
/* JSON-RPC parsing — edge cases */
RUN_TEST(jsonrpc_parse_empty_string);
RUN_TEST(jsonrpc_parse_missing_jsonrpc_field);
RUN_TEST(jsonrpc_parse_rejects_invalid_version_and_id);
RUN_TEST(jsonrpc_parse_missing_method);
RUN_TEST(jsonrpc_parse_string_id);
RUN_TEST(jsonrpc_parse_no_params);
@@ -20436,6 +20579,7 @@ SUITE(mcp) {
/* JSON-RPC formatting */
RUN_TEST(jsonrpc_format_response);
RUN_TEST(jsonrpc_format_response_rejects_missing_or_malformed_payload);
RUN_TEST(jsonrpc_format_error);
/* MCP protocol helpers */
@@ -20639,6 +20783,7 @@ SUITE(mcp) {
RUN_TEST(search_code_file_pattern_prefilter_boundaries);
RUN_TEST(search_code_windows_scope_prefilter_removes_pipeline_filter);
RUN_TEST(search_code_cancel_cleans_supervised_scan);
RUN_TEST(server_handle_logs_timeout_without_query);
RUN_TEST(search_code_output_limit_fails_closed_and_cleans_scan);
RUN_TEST(search_code_scan_deadline_fails_closed_and_resets);
RUN_TEST(search_code_scan_deadline_override_is_per_server);
@@ -20736,6 +20881,8 @@ SUITE(mcp) {
/* Poll/getline FILE* buffering fix */
#ifndef _WIN32
RUN_TEST(mcp_server_run_rapid_messages);
RUN_TEST(mcp_server_run_reports_output_failure);
RUN_TEST(mcp_server_run_reports_input_failure);
#endif
/* Snippet resolution (port of snippet_test.go) */