[mforce]

Closes #1227

What changes for a model and for the log

A model that sends a bad argument now learns which one and what shape it needs. Before, it got An error occurred invoking '<tool>'. and usually retried the same call.

Call	Before	After
cluckwork_list_daily_entries, from: "10/11/2026" or from: 123	An error occurred invoking 'cluckwork_list_daily_entries'.	... : from must be a date, YYYY-MM-DD.
cluckwork_list_flocks, limit: "ten", null or " 1"	generic	... : limit must be a whole number.
cluckwork_list_flocks, limit: 2147483648	generic	... : limit must be a whole number from -2147483648 to 2147483647.
cluckwork_list_sales_orders, customerId: "Acme"	generic	... : customerId must be an id.
cluckwork_record_daily_entry, grades: "invalid"	generic	... : grades must be a list.
cluckwork_record_daily_entry, grades: [1]	generic	... : grades[0] must be an object.
cluckwork_record_daily_entry, grades[0].quantity (or Quantity) set to "ten" or null	generic	... : grades[0].quantity must be a whole number.
cluckwork_record_daily_entry without date	generic	... : date is required.

A tool's own refusal (not found, ambiguous name, missing role inside the tool) reaches the model as before. It no longer logs "<tool>" threw an unhandled exception. at Error with a stack trace. It logs one Information line, MCP tool {Tool} refused the call., with no exception and no message text. The refusal text can carry what the model sent, such as a flock name, so it stays out of the log. A bad argument logs MCP tool {Tool} refused the call: argument {Argument} is invalid., naming only the parameter path.

Every other exception still logs at Error through the SDK, and the model still gets the generic message, so no internals leak. That includes faults from the tool's construction, its body and its result.

How it works

The change is one call-tool filter, McpToolErrors.Filter in src/Cluckwork.Api/Hosting/McpToolErrors.cs, registered in AddCluckworkMcp. Start reading there.

• Bad arguments are found before the tool runs. For each parameter the tool's input schema lists, the filter deserializes the supplied argument into the parameter's declared type with McpJsonUtilities.DefaultOptions, as the SDK's binder (AIFunctionFactory, Microsoft.Extensions.AI 10.8.3) will. The method comes from McpServerTool.Metadata, where the SDK puts the MethodInfo first. A missing argument with no default is "required". A JsonException from this step is a bad argument.
• The message names the canonical path. The serializer's exception path picks out the failing member, and the serializer's own property names give its spelling, so Quantity reports as grades[0].quantity. The schema only words the shape: format: date, format: uuid, type: integer and so on. A whole number that still fails to bind gets its declared type's range.
• Refusals are answered as results. The SDK (2.2.0, McpServerImpl.BuildComposedCallToolHandler) logs ToolCallError at Error for every exception that leaves the call-tool filter pipeline. When a filter returns a CallToolResult with IsError = true, the SDK logs only its Information "<tool>" completed. IsError = True. line. So the filter returns the result, with the same text CreateToolCallErrorResult would write, for a bad argument and for a tool's own McpException. No logging filter is needed.
• Nothing after the check is reclassified. McpProtocolException passes through, so a protocol error stays a JSON-RPC error. Any other exception from construction, the body or the result passes through to the SDK's Error path.

Not changed

When a client calls a tool its role or scope does not allow, the SDK's own authorization filter rejects the call before this filter runs. It throws McpProtocolException (InvalidRequest), and the SDK still logs that at Error. Only a client that ignores tools/list makes that call. Lowering it would need a logger decorator around the SDK's category, which is more than this issue needs.

Tests

tests/Cluckwork.Api.IntegrationTests/Mcp/McpToolErrorTests.cs uses a real MCP client, a real OAuth token, a per-host Serilog sink and probe tools that throw. It has 20 cases:

• 13 bad-argument cases, one per row above, each checking the reply and that nothing logged at Error.
• A numeric string limit: "2" that still reaches the tool body.
• The not-found refusal.
• A construction fault, once with a valid argument (Error, generic reply) and once with a bad one (the argument is named and nothing logs at Error).
• Three body faults (InvalidOperationException, JsonException, ArgumentException) and one protocol error.

Fourteen mutations each turned at least one case red. Removing the pre-invocation check turned 15 red. Widening the catch to treat JsonException or ArgumentException from the tool as a bad argument turned the construction-fault test and two body faults red. The others were catching protocol errors, not catching refusals, binding into JsonElement, binding with JsonSerializerOptions.Default, removing the required check, case-sensitive member lookup, no path walk, no range, the date and uuid shape words, and each log level raised to Error. Binding with JsonSerializerOptions.Web passes, because for these tools it is equivalent to DefaultOptions.

Locally, all 215 tests under Mcp. and the 386 Architecture tests in Cluckwork.Application.Tests pass.

Review

Codex reviewed f3413409 and found four defects in the first design, which inferred bad arguments from the schema after a failure. This head replaces that design with the binding check above. The reply with the before and after for each finding is #1238 (comment).

Live run

The first live run, on ee1a2bf7, is #1238 (comment). A rerun on the current head follows.

[mforce]

Live MCP client run

I ran this on an isolated stack (cw1227) built from head ee1a2bf7, behind the TLS proxy at https://localhost:8497. The Owner connected twice through real OAuth consent with the password step-up, once with farm:read and once with daily-entries:write. The calls below used the TypeScript SDK client (tools/verify/mcp/client.ts, protocol 2025-11-25). The 2026-07-28 rows used the C# probe (probe.cs, SDK 2.2.0).

Call	Reply to the model
cluckwork_list_daily_entries {"from":"10/11/2026"}	An error occurred invoking 'cluckwork_list_daily_entries': from must be a date, YYYY-MM-DD.
cluckwork_list_flocks {"limit":"ten"}	... : limit must be a whole number.
cluckwork_list_sales_orders {"customerId":"Acme"}	... : customerId must be an id.
cluckwork_record_daily_entry with grades[0].quantity: "ten"	... : grades[0].quantity must be a whole number.
cluckwork_record_daily_entry without date	... : date is required.
cluckwork_list_daily_entries {"flock":"No Such Flock"}	... : No flock you can see is named or numbered 'No Such Flock'.
cluckwork_list_egg_lot_movements with an unknown lotId	... : No egg lot 00000000-0000-0000-0000-000000000001 exists on this farm.
cluckwork_list_flocks {"limit":"2"} (control)	two flocks, complete: false, nextOffset: 2
2026-07-28, {"from":"10/11/2026"}	negotiated=2026-07-28, from must be a date, YYYY-MM-DD.
2026-07-28, {"flock":"No Such Flock"}	the same not-found refusal

The stack log for the call window has 102 events in compact JSON:

• None is at Warning or Error. None has an @l field, so every event is Information.
• None carries an exception (@x), and none says threw an unhandled exception.
• No Such Flock appears nowhere in the log.
• 9 events are MCP tool {Tool} refused the call. or ... argument {Argument} is invalid.. Each names only the tool and, for a bad argument, the parameter path (from, limit, customerId, grades[0].quantity, date).

The not-found refusal as logged:

{"@mt":"MCP tool {Tool} refused the call.","Tool":"cluckwork_list_daily_entries","EventId":{"Id":1856655997,"Name":"Refused"},"SourceContext":"Cluckwork.Api.Hosting.McpToolErrors", ...}
{"@mt":"\"{ToolName}\" completed. IsError = {IsError}.","ToolName":"cluckwork_list_daily_entries","IsError":true,"SourceContext":"ModelContextProtocol.Server.McpServer", ...}

I did not trigger a real fault on the live stack, because no tool there has one to provoke on demand. The in-process tests cover that case with probe tools that throw InvalidOperationException, JsonException and ArgumentException from the body. Each still logs at Error, and the reply is only An error occurred invoking '<tool>'..

The before state is the RED run of the same tests on this branch before the filter existed. All five bad-argument and refusal cases got the generic reply, and the not-found refusal logged McpException: No flock you can see is named or numbered 'No Such Flock'. at Error with its stack trace.

[mforce]

Codex review at f341340: R1 to R4 fixed in fc9ba60

Codex reviewed f3413409 and confirmed four defects with one root cause. The schema walker copied part of the SDK binder and disagreed with it. I took its design. The walker is gone, and fc9ba60b replaces it with a binding check that runs before the tool.

For each parameter the input schema lists, the filter deserializes the supplied argument into the parameter's declared type. It uses McpJsonUtilities.DefaultOptions and the MethodInfo the SDK puts first in McpServerTool.Metadata. A missing argument with no default is "required". A JsonException from that step is a bad argument. The serializer's path picks out the failing member, and the serializer's own property names give the canonical spelling. The schema only supplies the words for the shape. A whole number that still fails to bind gets its type's range. Anything thrown after the check stays on the SDK fault path, with a generic reply and an Error log. That covers construction, the tool body and the result. Refusal logging is unchanged.

Finding	Before (f3413409)	After (fc9ba60b)
R1, construction fault with {"date":"2026-10-11"}	Error, generic reply (unchanged)	Error, generic reply
R1, construction fault with {"date":"10/11/2026"}	named, because the walker guessed after the fault	named before the tool is constructed, so no fault occurs
R2, limit:null	generic, Error	limit must be a whole number.
R2, from:123	generic, Error	from must be a date, YYYY-MM-DD.
R2, grades:"invalid"	generic, Error	grades must be a list.
R2, grades:[1]	generic, Error	grades[0] must be an object.
R2, grades[0].quantity:null	generic, Error	grades[0].quantity must be a whole number.
R3, limit:2147483648	generic, Error	limit must be a whole number from -2147483648 to 2147483647.
R3, limit:" 1"	generic, Error	limit must be a whole number.
R4, grades[0].Quantity:"ten"	generic, Error	grades[0].quantity must be a whole number.

The R1 test asserts both halves in one call sequence. With a valid argument, the construction fault logs at Error and its text stays out of the reply. With a bad argument, the reply names date and nothing logs at Error. limit:"2" still reaches the tool body.

Verification.

• McpToolErrorTests has 20 cases. Every scenario in the review is a case, and the body-fault and protocol-error controls stay.
• The 20 cases also ran against the old filter. Nine failed: the five null, overflow and whitespace cases, grades:"invalid", grades:[1], the nested-null case and Quantity.
• Fourteen mutations each turned at least one case red:
  • removing the pre-invocation check (15 red)
  • widening the catch to treat JsonException and ArgumentException from the tool as bad arguments (the construction-fault test and two body faults red)
  • catching protocol errors
  • not catching refusals
  • binding into JsonElement
  • binding with JsonSerializerOptions.Default
  • removing the required check
  • case-sensitive member lookup
  • no path walk
  • no range
  • the date and uuid shape words
  • each log level raised to Error
• Binding with JsonSerializerOptions.Web passes all 20. It also reads numbers from strings and ignores member case, so for the current tools it is equivalent to DefaultOptions.
• All 215 tests under Mcp. and the 386 Architecture tests pass locally.

A live client rerun on the new head is next. I will add it as a comment.

[mforce]

Live MCP client rerun at a48257c

I reran on the isolated stack cw1227, rebuilt from head a48257cb, behind the TLS proxy at https://localhost:8497. The Owner connected through real OAuth consent with the password step-up and got a farm:read token. Calls used the TypeScript SDK client (protocol 2025-11-25) and the C# probe (2026-07-28).

Call	Reply to the model
cluckwork_list_daily_entries {"from":"10/11/2026"}	An error occurred invoking 'cluckwork_list_daily_entries': from must be a date, YYYY-MM-DD.
cluckwork_list_flocks {"limit":2147483648}	... : limit must be a whole number from -2147483648 to 2147483647.
cluckwork_list_flocks {"limit":null}	... : limit must be a whole number.
cluckwork_list_daily_entries {"flock":"No Such Flock"}	... : No flock you can see is named or numbered 'No Such Flock'.
cluckwork_list_flocks {"limit":"2"} (control)	two flocks, so the numeric string still binds
2026-07-28, cluckwork_list_flocks {"limit":2147483648}	negotiated=2026-07-28, the same range message

The stack log for the call window has 274 events in compact JSON:

• None has an @l field, so every event is Information.
• None carries an exception (@x), and none says threw an unhandled exception.
• No Such Flock appears nowhere in the log.

The filter's own events:

{"mt":"MCP tool {Tool} refused the call: argument {Argument} is invalid.","Tool":"cluckwork_list_daily_entries","Argument":"from","level":"Information","x":null}
{"mt":"MCP tool {Tool} refused the call: argument {Argument} is invalid.","Tool":"cluckwork_list_flocks","Argument":"limit","level":"Information","x":null}
{"mt":"MCP tool {Tool} refused the call: argument {Argument} is invalid.","Tool":"cluckwork_list_flocks","Argument":"limit","level":"Information","x":null}
{"mt":"MCP tool {Tool} refused the call.","Tool":"cluckwork_list_daily_entries","Argument":null,"level":"Information","x":null}
{"mt":"MCP tool {Tool} refused the call: argument {Argument} is invalid.","Tool":"cluckwork_list_flocks","Argument":"limit","level":"Information","x":null}

The last line is the 2026-07-28 overflow call. The construction-fault and body-fault cases need throwing probe tools, so the in-process tests cover them, not the live stack.