Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 28 additions & 2 deletions server/src/server/sse_emitter.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,30 @@ static int64_t unix_timestamp() {
std::chrono::system_clock::now().time_since_epoch()).count();
}

std::string escape_for_logging(const std::string & s) {
std::string out;
out.reserve(s.size() + 16);
for (unsigned char c : s) {
switch (c) {
case '\n': out += "\\n"; break;
case '\r': out += "\\r"; break;
case '\t': out += "\\t"; break;
case '\\': out += "\\\\"; break;
case '\'': out += "\\'"; break;
default:
if (c < 0x20 || c == 0x7f) {
char hex[8];
std::snprintf(hex, sizeof(hex), "\\u00%02x", (unsigned int) c);
out += hex;
} else {
out += (char) c;
}
break;
}
}
return out;
}

// Round `x` to 1 decimal place. JSON serialization of doubles can emit
// 17 significant digits which is noisy in client logs and bench output;
// caller-side rounding keeps the wire format stable across runs.
Expand Down Expand Up @@ -835,10 +859,12 @@ std::vector<std::string> SseEmitter::emit_finish(int completion_tokens,
} else {
// Tool syntax was detected but no valid call parsed. Do not leak
// malformed/incomplete XML back to the user or reasoning channel.
std::string escaped = escape_for_logging(tool_buffer_);
std::fprintf(stderr,
"[server] tool_call parse failed; suppressing buffered tool text "
"request_id=%s format=%d bytes=%zu\n",
request_id_.c_str(), (int)format_, tool_buffer_.size());
"request_id=%s format=%d bytes=%zu text='%s'\n",
request_id_.c_str(), (int)format_, tool_buffer_.size(),
escaped.c_str());

if (tool_from_reasoning_) {
size_t think_close = find_top_level_think_close(tool_buffer_, tools_);
Expand Down
2 changes: 2 additions & 0 deletions server/src/server/sse_emitter.h
Original file line number Diff line number Diff line change
Expand Up @@ -208,4 +208,6 @@ class SseEmitter {
static constexpr size_t BASE_HOLDBACK = 15; // len("<parameter name=") - 1
};

std::string escape_for_logging(const std::string & s);

} // namespace dflash::common
78 changes: 78 additions & 0 deletions server/test/test_server_unit.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -6522,3 +6522,81 @@ TEST_CASE(ServerUnitFixture, test_emitter_streaming_malformed_tool_in_think_answ
TEST_ASSERT(em.tool_calls().empty());
TEST_ASSERT(em.accumulated_text() == "The output is </parameter> end.");
}

TEST_CASE(ServerUnitFixture, test_escape_for_logging) {
// Standard escapes
TEST_ASSERT(escape_for_logging("hello\nworld\r\t'\\") == "hello\\nworld\\r\\t\\'\\\\");
// NUL byte (escaped as fixed-width \u0000 for consistency)
TEST_ASSERT(escape_for_logging(std::string("null\0byte", 9)) == "null\\u0000byte");
// Control byte followed by hex digit must be unambiguous (\u0001f)
TEST_ASSERT(escape_for_logging(std::string("\x01", 1) + "f") == "\\u0001f");
TEST_ASSERT(escape_for_logging(std::string("\x1f", 1) + "abc") == "\\u001fabc");
TEST_ASSERT(escape_for_logging(std::string("\x7f", 1) + "xyz") == "\\u007fxyz");
}

namespace {
struct StderrCapture {
int old_stderr = -1;
std::FILE * file = nullptr;

StderrCapture() {
std::fflush(stderr);
file = std::tmpfile();
if (file == nullptr) return;

old_stderr = dup(STDERR_FILENO);
if (old_stderr == -1 || dup2(fileno(file), STDERR_FILENO) == -1) {
if (old_stderr != -1) close(old_stderr);
old_stderr = -1;
std::fclose(file);
file = nullptr;
}
}

std::string str() {
Comment thread
cubic-dev-ai[bot] marked this conversation as resolved.
restore();
if (file == nullptr) return "";

std::rewind(file);
std::string out;
char buf[1024];
size_t n = 0;
while ((n = std::fread(buf, 1, sizeof(buf), file)) > 0) {
out.append(buf, n);
}
std::fclose(file);
file = nullptr;
return out;
}

void restore() {
if (old_stderr != -1) {
std::fflush(stderr);
dup2(old_stderr, STDERR_FILENO);
close(old_stderr);
old_stderr = -1;
}
}

~StderrCapture() {
restore();
if (file != nullptr) std::fclose(file);
}
};
} // namespace

TEST_CASE(ServerUnitFixture, test_emitter_suppresses_malformed_multiline_tool_buffer) {
StderrCapture capture;

auto em = make_emitter(ApiFormat::OPENAI_CHAT, read_tools(), false);
em.emit_start();
em.emit_token("<function_call>\n <invoke name=\"read\">\n malformed prose body with\nnew lines and \t tabs\n");
em.emit_finish(10);

std::string captured = capture.str();

TEST_ASSERT(em.tool_calls().empty());
TEST_ASSERT(em.accumulated_text().empty());
TEST_ASSERT(captured.find("[server] tool_call parse failed; suppressing buffered tool text") != std::string::npos);
TEST_ASSERT(captured.find("text='<function_call>\\n <invoke name=\"read\">\\n malformed prose body with\\nnew lines and \\t tabs\\n'") != std::string::npos);
}
Loading