From af87389dac0d5345e6211fe97713f31c0c762b93 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 18:34:52 +0800 Subject: [PATCH 1/8] refactor(logging): simplify console logging --- src/deepseek_cursor_proxy/server.py | 31 ++++++++++++++++-- tests/test_server.py | 51 +++++++++++++++++++++++++++++ 2 files changed, 79 insertions(+), 3 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index ae4181e..7287b73 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -35,6 +35,32 @@ LOG = logging.getLogger("deepseek_cursor_proxy") +DEFAULT_INFO_LOG_FORMAT = "%(message)s" +DEFAULT_WARNING_LOG_FORMAT = "%(levelname)s %(message)s" +VERBOSE_LOG_FORMAT = "%(asctime)s %(levelname)s %(message)s" + + +class ConsoleLogFormatter(logging.Formatter): + def __init__(self, *, verbose: bool) -> None: + super().__init__() + self.verbose = verbose + self._verbose_formatter = logging.Formatter(VERBOSE_LOG_FORMAT) + self._info_formatter = logging.Formatter(DEFAULT_INFO_LOG_FORMAT) + self._warning_formatter = logging.Formatter(DEFAULT_WARNING_LOG_FORMAT) + + def format(self, record: logging.LogRecord) -> str: + if self.verbose: + return self._verbose_formatter.format(record) + if record.levelno <= logging.INFO: + return self._info_formatter.format(record) + return self._warning_formatter.format(record) + + +def configure_logging(*, verbose: bool) -> None: + handler = logging.StreamHandler() + handler.setFormatter(ConsoleLogFormatter(verbose=verbose)) + logging.basicConfig(level=logging.INFO, handlers=[handler], force=True) + class RequestBodyTooLarge(ValueError): pass @@ -1216,13 +1242,11 @@ def warn_if_insecure_upstream(url: str) -> None: def main(argv: list[str] | None = None) -> int: - logging.basicConfig( - level=logging.INFO, format="%(asctime)s %(levelname)s %(message)s" - ) args = build_arg_parser().parse_args(argv) try: config = ProxyConfig.from_file(config_path=args.config_path) except ValueError as exc: + configure_logging(verbose=bool(args.verbose)) LOG.error("%s", exc) return 2 updates: dict[str, Any] = {} @@ -1267,6 +1291,7 @@ def main(argv: list[str] | None = None) -> int: if updates: config = replace(config, **updates) + configure_logging(verbose=config.verbose) warn_if_insecure_upstream(config.upstream_base_url) store = ReasoningStore( config.reasoning_content_path, diff --git a/tests/test_server.py b/tests/test_server.py index 7788229..143530c 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -14,7 +14,9 @@ from io import BytesIO import gzip import json +import logging from pathlib import Path +import re import threading import time from types import SimpleNamespace @@ -26,6 +28,7 @@ from deepseek_cursor_proxy.config import ProxyConfig from deepseek_cursor_proxy.reasoning_store import ReasoningStore from deepseek_cursor_proxy.server import ( + ConsoleLogFormatter, DeepSeekProxyHandler, DeepSeekProxyServer, build_arg_parser, @@ -119,6 +122,54 @@ def test_cli_boolean_flags_have_on_and_off_forms(self) -> None: self.assertTrue(args.cors) self.assertEqual(args.trace_dir, Path("/tmp/dcp-traces")) + def test_default_console_logging_hides_info_prefix_and_timestamp(self) -> None: + formatter = ConsoleLogFormatter(verbose=False) + info_record = logging.LogRecord( + "deepseek_cursor_proxy", + logging.INFO, + __file__, + 1, + "listening on %s", + ("http://127.0.0.1:9000/v1",), + None, + ) + warning_record = logging.LogRecord( + "deepseek_cursor_proxy", + logging.WARNING, + __file__, + 1, + "trace logging enabled", + (), + None, + ) + + self.assertEqual( + formatter.format(info_record), + "listening on http://127.0.0.1:9000/v1", + ) + self.assertEqual( + formatter.format(warning_record), "WARNING trace logging enabled" + ) + + def test_verbose_console_logging_shows_timestamp_and_level(self) -> None: + formatter = ConsoleLogFormatter(verbose=True) + record = logging.LogRecord( + "deepseek_cursor_proxy", + logging.INFO, + __file__, + 1, + "listening on %s", + ("http://127.0.0.1:9000/v1",), + None, + ) + + self.assertRegex( + formatter.format(record), + re.compile( + r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} INFO listening on " + ), + ) + def test_read_response_body_decodes_gzip_and_deflate(self) -> None: self.assertEqual( read_response_body(_FakeResponse(gzip.compress(b'{"ok":1}'), "gzip")), From 7eaad4c17db6839258ebcdd3818980cdb972c252 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 18:48:35 +0800 Subject: [PATCH 2/8] refactor(server): simplify startup logging --- src/deepseek_cursor_proxy/server.py | 66 +++++++++++++++-------------- 1 file changed, 34 insertions(+), 32 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index 7287b73..a25e5cc 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -1316,37 +1316,8 @@ def main(argv: list[str] | None = None) -> int: server.reasoning_store = store server.trace_writer = trace_writer - LOG.info("listening on http://%s:%s/v1", config.host, config.port) - LOG.info( - "forwarding to %s/chat/completions default_model=%s", - config.upstream_base_url, - config.upstream_model, - ) - LOG.info( - ( - "thinking=%s reasoning_effort=%s display_reasoning=%s " - "collapsible_reasoning=%s missing_reasoning_strategy=%s " - "reasoning_content_path=%s" - ), - config.thinking, - config.reasoning_effort, - config.display_reasoning, - config.collapsible_reasoning, - config.missing_reasoning_strategy, - config.reasoning_content_path, - ) - if config.verbose: - LOG.info("logging mode=verbose metadata=detailed bodies=true") - LOG.warning( - "verbose logging enabled; prompts and code may be written to stdout" - ) - else: - LOG.info("logging mode=normal metadata=safe_summaries bodies=false") - if trace_writer is not None: - LOG.info("trace session directory: %s", trace_writer.session_dir) - LOG.warning("trace logging enabled; prompts and code will be written to disk") - tunnel: NgrokTunnel | None = None + public_url: str | None = None if config.ngrok: target_url = local_tunnel_target(config.host, config.port) tunnel = NgrokTunnel(target_url) @@ -1357,8 +1328,39 @@ def main(argv: list[str] | None = None) -> int: server.server_close() store.close() return 2 - LOG.info("ngrok tunnel forwarding %s -> %s", public_url, target_url) - LOG.info("api base url: %s/v1", public_url.rstrip("/")) + local_base_url = f"http://{config.host}:{config.port}/v1" + api_base_url = ( + f"{public_url.rstrip('/')}/v1" if public_url is not None else local_base_url + ) + + LOG.info( + "default_model: %s (%s, %s)", + config.upstream_model, + "thinking" if config.thinking == "enabled" else "no thinking", + config.reasoning_effort, + ) + + if config.verbose: + display_reasoning = "off" + if config.display_reasoning: + display_reasoning = ( + "on (collapsible)" if config.collapsible_reasoning else "on" + ) + LOG.info("display_reasoning: %s", display_reasoning) + LOG.info("missing_reasoning_strategy: %s", config.missing_reasoning_strategy) + LOG.info("reasoning_cache: %s", config.reasoning_content_path) + LOG.warning( + "verbose logging enabled; prompts and code may be written to stdout" + ) + if trace_writer is not None: + LOG.info("trace_dir: %s", trace_writer.session_dir) + LOG.warning("trace logging enabled; prompts and code will be written to disk") + if public_url is None and not config.ngrok: + LOG.info("public_tunnel: off") + if config.verbose: + LOG.info("upstream_url: %s/chat/completions", config.upstream_base_url) + LOG.info("local_base_url: %s", local_base_url) + LOG.info("api_base_url: %s", api_base_url) try: server.serve_forever() except KeyboardInterrupt: From 0957730acaa2a7638d5ca4dbd103a1d6bbe35f95 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 18:56:51 +0800 Subject: [PATCH 3/8] feat(server): add stats spinner for streaming --- src/deepseek_cursor_proxy/server.py | 149 ++++++++++++++++++++-------- tests/test_server.py | 32 ++++++ 2 files changed, 138 insertions(+), 43 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index a25e5cc..38f6e69 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -9,6 +9,7 @@ from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer from pathlib import Path import sys +import threading import time from typing import Any from urllib.error import HTTPError, URLError @@ -62,6 +63,55 @@ def configure_logging(*, verbose: bool) -> None: logging.basicConfig(level=logging.INFO, handlers=[handler], force=True) +class StatsSpinner: + frames = ("⠋", "⠙", "⠹") + text = "└ stats {frame} streaming..." + + def __init__( + self, + *, + enabled: bool, + stream: Any | None = None, + interval: float = 0.12, + ) -> None: + self.stream = stream if stream is not None else sys.stderr + self.enabled = enabled and bool(getattr(self.stream, "isatty", lambda: False)()) + self.interval = interval + self._stop = threading.Event() + self._thread: threading.Thread | None = None + self._visible = False + + def start(self) -> "StatsSpinner": + if not self.enabled or self._thread is not None: + return self + self._thread = threading.Thread(target=self._run, daemon=True) + self._thread.start() + return self + + def stop(self) -> None: + if not self.enabled: + return + self._stop.set() + if self._thread is not None: + self._thread.join(timeout=1) + self._thread = None + if self._visible: + self.stream.write( + "\r" + (" " * len(self.text.format(frame=self.frames[0]))) + "\r" + ) + self.stream.flush() + self._visible = False + + def _run(self) -> None: + index = 0 + while not self._stop.is_set(): + self.stream.write("\r" + self.text.format(frame=self.frames[index])) + self.stream.flush() + self._visible = True + index = (index + 1) % len(self.frames) + self._stop.wait(self.interval) + + class RequestBodyTooLarge(ValueError): pass @@ -264,12 +314,16 @@ def do_POST(self) -> None: ) log_send_summary(prepared) + stats_spinner = StatsSpinner( + enabled=bool(prepared.payload.get("stream")) and not self.config.verbose + ).start() try: if self.config.verbose: LOG.info("forwarding to %s", upstream_url) response = urlopen(request, timeout=self.config.request_timeout) except HTTPError as exc: + stats_spinner.stop() LOG.warning( "request failed upstream_status=%s stream=%s elapsed_ms=%s", exc.code, @@ -285,6 +339,7 @@ def do_POST(self) -> None: ) return except URLError as exc: + stats_spinner.stop() LOG.warning( "upstream request failed elapsed_ms=%s reason=%s", elapsed_ms(started), @@ -297,55 +352,63 @@ def do_POST(self) -> None: ) self._finish_trace(trace, "upstream_error", http_status=502) return + except Exception: + stats_spinner.stop() + raise - with response: - upstream_status = getattr(response, "status", 200) - if self.config.verbose: - LOG.info( - "upstream response status=%s stream=%s elapsed_ms=%s", - upstream_status, - bool(prepared.payload.get("stream")), - elapsed_ms(started), - ) - if prepared.payload.get("stream"): - sent_response = self._proxy_streaming_response( - response, - prepared.original_model, - prepared.payload["messages"], - prepared.cache_namespace, - prepared.recovery_notice, - trace=trace, - record_response_scope=prepared.record_response_scope, - record_response_messages=prepared.record_response_messages, - record_response_contexts=prepared.record_response_contexts, - ) - else: - sent_response = self._proxy_regular_response( - response, - prepared.original_model, - prepared.payload["messages"], - prepared.cache_namespace, - prepared.recovery_notice, - trace=trace, - record_response_scope=prepared.record_response_scope, - record_response_messages=prepared.record_response_messages, - record_response_contexts=prepared.record_response_contexts, - ) - if not sent_response.sent: + try: + with response: + upstream_status = getattr(response, "status", 200) + if self.config.verbose: + LOG.info( + "upstream response status=%s stream=%s elapsed_ms=%s", + upstream_status, + bool(prepared.payload.get("stream")), + elapsed_ms(started), + ) + if prepared.payload.get("stream"): + sent_response = self._proxy_streaming_response( + response, + prepared.original_model, + prepared.payload["messages"], + prepared.cache_namespace, + prepared.recovery_notice, + trace=trace, + record_response_scope=prepared.record_response_scope, + record_response_messages=prepared.record_response_messages, + record_response_contexts=prepared.record_response_contexts, + ) + else: + sent_response = self._proxy_regular_response( + response, + prepared.original_model, + prepared.payload["messages"], + prepared.cache_namespace, + prepared.recovery_notice, + trace=trace, + record_response_scope=prepared.record_response_scope, + record_response_messages=prepared.record_response_messages, + record_response_contexts=prepared.record_response_contexts, + ) + if not sent_response.sent: + stats_spinner.stop() + self._finish_trace( + trace, + "client_disconnected", + http_status=upstream_status, + stream=bool(prepared.payload.get("stream")), + ) + return + stats_spinner.stop() + log_stats_summary(sent_response.usage) self._finish_trace( trace, - "client_disconnected", + "completed", http_status=upstream_status, stream=bool(prepared.payload.get("stream")), ) - return - log_stats_summary(sent_response.usage) - self._finish_trace( - trace, - "completed", - http_status=upstream_status, - stream=bool(prepared.payload.get("stream")), - ) + finally: + stats_spinner.stop() def _start_trace(self, request_path: str) -> TraceRequest | None: writer = self.trace_writer diff --git a/tests/test_server.py b/tests/test_server.py index 143530c..92f3294 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -31,6 +31,7 @@ ConsoleLogFormatter, DeepSeekProxyHandler, DeepSeekProxyServer, + StatsSpinner, build_arg_parser, read_response_body, summarize_chat_payload, @@ -83,6 +84,21 @@ def flush(self) -> None: raise BrokenPipeError("test disconnect") +class _FakeConsole: + def __init__(self, *, tty: bool) -> None: + self.tty = tty + self.writes: list[str] = [] + + def isatty(self) -> bool: + return self.tty + + def write(self, text: str) -> None: + self.writes.append(text) + + def flush(self) -> None: + return + + def _make_handler_stub(wfile: object, **config: object) -> DeepSeekProxyHandler: handler = object.__new__(DeepSeekProxyHandler) handler.server = SimpleNamespace( @@ -170,6 +186,22 @@ def test_verbose_console_logging_shows_timestamp_and_level(self) -> None: ), ) + def test_stats_spinner_animates_only_for_tty(self) -> None: + tty = _FakeConsole(tty=True) + spinner = StatsSpinner(enabled=True, stream=tty, interval=0.001).start() + deadline = time.monotonic() + 0.2 + while time.monotonic() < deadline and not tty.writes: + time.sleep(0.001) + spinner.stop() + + output = "".join(tty.writes) + self.assertIn("└ stats ⠋ streaming...", output) + self.assertTrue(output.endswith("\r")) + + non_tty = _FakeConsole(tty=False) + StatsSpinner(enabled=True, stream=non_tty, interval=0.001).start().stop() + self.assertEqual(non_tty.writes, []) + def test_read_response_body_decodes_gzip_and_deflate(self) -> None: self.assertEqual( read_response_body(_FakeResponse(gzip.compress(b'{"ok":1}'), "gzip")), From f2e0a167fe26041861fc4d63c4ae7d1efd5b2df7 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 19:12:48 +0800 Subject: [PATCH 4/8] refactor(spinner): rename StatsSpinner to TerminalSpinner --- src/deepseek_cursor_proxy/server.py | 40 ++++++++++++++++++----------- tests/test_server.py | 18 ++++++++----- 2 files changed, 37 insertions(+), 21 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index 38f6e69..84a35ce 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -63,27 +63,32 @@ def configure_logging(*, verbose: bool) -> None: logging.basicConfig(level=logging.INFO, handlers=[handler], force=True) -class StatsSpinner: - frames = ("⠋", "⠙", "⠹") - text = "└ stats {frame} streaming..." +class TerminalSpinner: + hide_cursor = "\x1b[?25l" + show_cursor = "\x1b[?25h" + frames = ("⠋", "⠙", "⠹", "⠸", "⠼", "⠴", "⠦", "⠧", "⠇", "⠏") def __init__( self, *, enabled: bool, + text: str, stream: Any | None = None, interval: float = 0.12, ) -> None: self.stream = stream if stream is not None else sys.stderr self.enabled = enabled and bool(getattr(self.stream, "isatty", lambda: False)()) + self.text = text self.interval = interval self._stop = threading.Event() self._thread: threading.Thread | None = None self._visible = False - def start(self) -> "StatsSpinner": + def start(self) -> "TerminalSpinner": if not self.enabled or self._thread is not None: return self + self.stream.write(self.hide_cursor) + self.stream.flush() self._thread = threading.Thread(target=self._run, daemon=True) self._thread.start() return self @@ -96,11 +101,11 @@ def stop(self) -> None: self._thread.join(timeout=1) self._thread = None if self._visible: - self.stream.write( - "\r" + (" " * len(self.text.format(frame=self.frames[0]))) + "\r" - ) + self.stream.write("\r" + (" " * self._clear_width()) + "\r") self.stream.flush() self._visible = False + self.stream.write(self.show_cursor) + self.stream.flush() def _run(self) -> None: index = 0 @@ -111,6 +116,9 @@ def _run(self) -> None: index = (index + 1) % len(self.frames) self._stop.wait(self.interval) + def _clear_width(self) -> int: + return max(len(self.text.format(frame=frame)) for frame in self.frames) + class RequestBodyTooLarge(ValueError): pass @@ -314,8 +322,9 @@ def do_POST(self) -> None: ) log_send_summary(prepared) - stats_spinner = StatsSpinner( - enabled=bool(prepared.payload.get("stream")) and not self.config.verbose + spinner = TerminalSpinner( + enabled=bool(prepared.payload.get("stream")) and not self.config.verbose, + text="└ {frame}", ).start() try: @@ -323,7 +332,7 @@ def do_POST(self) -> None: LOG.info("forwarding to %s", upstream_url) response = urlopen(request, timeout=self.config.request_timeout) except HTTPError as exc: - stats_spinner.stop() + spinner.stop() LOG.warning( "request failed upstream_status=%s stream=%s elapsed_ms=%s", exc.code, @@ -339,7 +348,7 @@ def do_POST(self) -> None: ) return except URLError as exc: - stats_spinner.stop() + spinner.stop() LOG.warning( "upstream request failed elapsed_ms=%s reason=%s", elapsed_ms(started), @@ -353,7 +362,7 @@ def do_POST(self) -> None: self._finish_trace(trace, "upstream_error", http_status=502) return except Exception: - stats_spinner.stop() + spinner.stop() raise try: @@ -391,7 +400,7 @@ def do_POST(self) -> None: record_response_contexts=prepared.record_response_contexts, ) if not sent_response.sent: - stats_spinner.stop() + spinner.stop() self._finish_trace( trace, "client_disconnected", @@ -399,7 +408,7 @@ def do_POST(self) -> None: stream=bool(prepared.payload.get("stream")), ) return - stats_spinner.stop() + spinner.stop() log_stats_summary(sent_response.usage) self._finish_trace( trace, @@ -408,7 +417,7 @@ def do_POST(self) -> None: stream=bool(prepared.payload.get("stream")), ) finally: - stats_spinner.stop() + spinner.stop() def _start_trace(self, request_path: str) -> TraceRequest | None: writer = self.trace_writer @@ -1424,6 +1433,7 @@ def main(argv: list[str] | None = None) -> int: LOG.info("upstream_url: %s/chat/completions", config.upstream_base_url) LOG.info("local_base_url: %s", local_base_url) LOG.info("api_base_url: %s", api_base_url) + LOG.info("■ ready") try: server.serve_forever() except KeyboardInterrupt: diff --git a/tests/test_server.py b/tests/test_server.py index 92f3294..5c16cf6 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -31,7 +31,7 @@ ConsoleLogFormatter, DeepSeekProxyHandler, DeepSeekProxyServer, - StatsSpinner, + TerminalSpinner, build_arg_parser, read_response_body, summarize_chat_payload, @@ -186,20 +186,26 @@ def test_verbose_console_logging_shows_timestamp_and_level(self) -> None: ), ) - def test_stats_spinner_animates_only_for_tty(self) -> None: + def test_terminal_spinner_animates_only_for_tty(self) -> None: tty = _FakeConsole(tty=True) - spinner = StatsSpinner(enabled=True, stream=tty, interval=0.001).start() + spinner = TerminalSpinner( + enabled=True, text="└ {frame}", stream=tty, interval=0.001 + ).start() deadline = time.monotonic() + 0.2 while time.monotonic() < deadline and not tty.writes: time.sleep(0.001) spinner.stop() output = "".join(tty.writes) - self.assertIn("└ stats ⠋ streaming...", output) - self.assertTrue(output.endswith("\r")) + self.assertIn(TerminalSpinner.hide_cursor, output) + self.assertIn("└ ⠋", output) + self.assertIn(TerminalSpinner.show_cursor, output) + self.assertTrue(output.endswith(TerminalSpinner.show_cursor)) non_tty = _FakeConsole(tty=False) - StatsSpinner(enabled=True, stream=non_tty, interval=0.001).start().stop() + TerminalSpinner( + enabled=True, text="└ {frame}", stream=non_tty, interval=0.001 + ).start().stop() self.assertEqual(non_tty.writes, []) def test_read_response_body_decodes_gzip_and_deflate(self) -> None: From 422e9cd4082686d5e21bffab51ee89131de77ca4 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 19:21:15 +0800 Subject: [PATCH 5/8] refactor(logging): extract logging module --- src/deepseek_cursor_proxy/logging.py | 96 +++++++++++++++++++++++ src/deepseek_cursor_proxy/server.py | 101 ++----------------------- src/deepseek_cursor_proxy/transform.py | 5 +- src/deepseek_cursor_proxy/tunnel.py | 4 +- tests/test_server.py | 6 +- 5 files changed, 110 insertions(+), 102 deletions(-) create mode 100644 src/deepseek_cursor_proxy/logging.py diff --git a/src/deepseek_cursor_proxy/logging.py b/src/deepseek_cursor_proxy/logging.py new file mode 100644 index 0000000..13ccf0e --- /dev/null +++ b/src/deepseek_cursor_proxy/logging.py @@ -0,0 +1,96 @@ +from __future__ import annotations + +import logging as stdlib_logging +import sys +import threading +from typing import Any + + +LOG = stdlib_logging.getLogger("deepseek_cursor_proxy") + +DEFAULT_INFO_LOG_FORMAT = "%(message)s" +DEFAULT_WARNING_LOG_FORMAT = "%(levelname)s %(message)s" +VERBOSE_LOG_FORMAT = "%(asctime)s %(levelname)s %(message)s" + + +class ConsoleLogFormatter(stdlib_logging.Formatter): + def __init__(self, *, verbose: bool) -> None: + super().__init__() + self.verbose = verbose + self._verbose_formatter = stdlib_logging.Formatter(VERBOSE_LOG_FORMAT) + self._info_formatter = stdlib_logging.Formatter(DEFAULT_INFO_LOG_FORMAT) + self._warning_formatter = stdlib_logging.Formatter(DEFAULT_WARNING_LOG_FORMAT) + + def format(self, record: stdlib_logging.LogRecord) -> str: + if self.verbose: + return self._verbose_formatter.format(record) + if record.levelno <= stdlib_logging.INFO: + return self._info_formatter.format(record) + return self._warning_formatter.format(record) + + +def configure_logging(*, verbose: bool) -> None: + handler = stdlib_logging.StreamHandler() + handler.setFormatter(ConsoleLogFormatter(verbose=verbose)) + stdlib_logging.basicConfig( + level=stdlib_logging.INFO, + handlers=[handler], + force=True, + ) + + +class TerminalSpinner: + hide_cursor = "\x1b[?25l" + show_cursor = "\x1b[?25h" + frames = ("⠋", "⠙", "⠹", "⠸", "⠼", "⠴", "⠦", "⠧", "⠇", "⠏") + + def __init__( + self, + *, + enabled: bool, + text: str, + stream: Any | None = None, + interval: float = 0.12, + ) -> None: + self.stream = stream if stream is not None else sys.stderr + self.enabled = enabled and bool(getattr(self.stream, "isatty", lambda: False)()) + self.text = text + self.interval = interval + self._stop = threading.Event() + self._thread: threading.Thread | None = None + self._visible = False + + def start(self) -> "TerminalSpinner": + if not self.enabled or self._thread is not None: + return self + self.stream.write(self.hide_cursor) + self.stream.flush() + self._thread = threading.Thread(target=self._run, daemon=True) + self._thread.start() + return self + + def stop(self) -> None: + if not self.enabled: + return + self._stop.set() + if self._thread is not None: + self._thread.join(timeout=1) + self._thread = None + if self._visible: + self.stream.write("\r" + (" " * self._clear_width()) + "\r") + self.stream.flush() + self._visible = False + self.stream.write(self.show_cursor) + self.stream.flush() + + def _run(self) -> None: + index = 0 + while not self._stop.is_set(): + self.stream.write("\r" + self.text.format(frame=self.frames[index])) + self.stream.flush() + self._visible = True + index = (index + 1) % len(self.frames) + self._stop.wait(self.interval) + + def _clear_width(self) -> int: + return max(len(self.text.format(frame=frame)) for frame in self.frames) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index 84a35ce..eedd5e0 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -5,11 +5,9 @@ import gzip from http.client import HTTPException import json -import logging from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer from pathlib import Path import sys -import threading import time from typing import Any from urllib.error import HTTPError, URLError @@ -22,104 +20,22 @@ default_config_path, default_reasoning_content_path, ) +from .logging import ( + LOG, + TerminalSpinner, + configure_logging, +) from .reasoning_store import ReasoningStore, conversation_scope from .streaming import CursorReasoningDisplayAdapter, StreamAccumulator from .trace import TraceRequest, TraceWriter from .tunnel import NgrokTunnel, local_tunnel_target from .transform import ( - PreparedRequest, RECOVERY_NOTICE_CONTENT, prepare_upstream_request, rewrite_response_body, ) -LOG = logging.getLogger("deepseek_cursor_proxy") - -DEFAULT_INFO_LOG_FORMAT = "%(message)s" -DEFAULT_WARNING_LOG_FORMAT = "%(levelname)s %(message)s" -VERBOSE_LOG_FORMAT = "%(asctime)s %(levelname)s %(message)s" - - -class ConsoleLogFormatter(logging.Formatter): - def __init__(self, *, verbose: bool) -> None: - super().__init__() - self.verbose = verbose - self._verbose_formatter = logging.Formatter(VERBOSE_LOG_FORMAT) - self._info_formatter = logging.Formatter(DEFAULT_INFO_LOG_FORMAT) - self._warning_formatter = logging.Formatter(DEFAULT_WARNING_LOG_FORMAT) - - def format(self, record: logging.LogRecord) -> str: - if self.verbose: - return self._verbose_formatter.format(record) - if record.levelno <= logging.INFO: - return self._info_formatter.format(record) - return self._warning_formatter.format(record) - - -def configure_logging(*, verbose: bool) -> None: - handler = logging.StreamHandler() - handler.setFormatter(ConsoleLogFormatter(verbose=verbose)) - logging.basicConfig(level=logging.INFO, handlers=[handler], force=True) - - -class TerminalSpinner: - hide_cursor = "\x1b[?25l" - show_cursor = "\x1b[?25h" - frames = ("⠋", "⠙", "⠹", "⠸", "⠼", "⠴", "⠦", "⠧", "⠇", "⠏") - - def __init__( - self, - *, - enabled: bool, - text: str, - stream: Any | None = None, - interval: float = 0.12, - ) -> None: - self.stream = stream if stream is not None else sys.stderr - self.enabled = enabled and bool(getattr(self.stream, "isatty", lambda: False)()) - self.text = text - self.interval = interval - self._stop = threading.Event() - self._thread: threading.Thread | None = None - self._visible = False - - def start(self) -> "TerminalSpinner": - if not self.enabled or self._thread is not None: - return self - self.stream.write(self.hide_cursor) - self.stream.flush() - self._thread = threading.Thread(target=self._run, daemon=True) - self._thread.start() - return self - - def stop(self) -> None: - if not self.enabled: - return - self._stop.set() - if self._thread is not None: - self._thread.join(timeout=1) - self._thread = None - if self._visible: - self.stream.write("\r" + (" " * self._clear_width()) + "\r") - self.stream.flush() - self._visible = False - self.stream.write(self.show_cursor) - self.stream.flush() - - def _run(self) -> None: - index = 0 - while not self._stop.is_set(): - self.stream.write("\r" + self.text.format(frame=self.frames[index])) - self.stream.flush() - self._visible = True - index = (index + 1) % len(self.frames) - self._stop.wait(self.interval) - - def _clear_width(self) -> int: - return max(len(self.text.format(frame=frame)) for frame in self.frames) - - class RequestBodyTooLarge(ValueError): pass @@ -1103,7 +1019,7 @@ def log_cursor_request( ) -def log_context_summary(prepared: PreparedRequest) -> None: +def log_context_summary(prepared: Any) -> None: LOG.info( "├ context filled=%s missing=%s recovered=%s dropped=%s status=%s", format_count(prepared.patched_reasoning_messages), @@ -1114,7 +1030,7 @@ def log_context_summary(prepared: PreparedRequest) -> None: ) -def log_send_summary(prepared: PreparedRequest) -> None: +def log_send_summary(prepared: Any) -> None: LOG.info( "├ send user_msgs=%s messages=%s tools=%s reasoning_content=%s", format_count(user_message_count(prepared.payload)), @@ -1134,7 +1050,7 @@ def log_stats_summary(usage: dict[str, Any] | None) -> None: ) -def context_status(prepared: PreparedRequest) -> str: +def context_status(prepared: Any) -> str: if prepared.recovered_reasoning_messages: return "recovered" if prepared.missing_reasoning_messages: @@ -1433,7 +1349,6 @@ def main(argv: list[str] | None = None) -> int: LOG.info("upstream_url: %s/chat/completions", config.upstream_base_url) LOG.info("local_base_url: %s", local_base_url) LOG.info("api_base_url: %s", api_base_url) - LOG.info("■ ready") try: server.serve_forever() except KeyboardInterrupt: diff --git a/src/deepseek_cursor_proxy/transform.py b/src/deepseek_cursor_proxy/transform.py index 40d5cdc..0053d98 100644 --- a/src/deepseek_cursor_proxy/transform.py +++ b/src/deepseek_cursor_proxy/transform.py @@ -3,11 +3,11 @@ from dataclasses import dataclass, field import hashlib import json -import logging import re from typing import Any from .config import ProxyConfig +from .logging import LOG from .reasoning_store import ( ReasoningStore, conversation_scope, @@ -20,9 +20,6 @@ from .streaming import fold_reasoning_into_content -LOG = logging.getLogger("deepseek_cursor_proxy") - - SUPPORTED_REQUEST_FIELDS = { "model", "messages", diff --git a/src/deepseek_cursor_proxy/tunnel.py b/src/deepseek_cursor_proxy/tunnel.py index d2a09c5..005b134 100644 --- a/src/deepseek_cursor_proxy/tunnel.py +++ b/src/deepseek_cursor_proxy/tunnel.py @@ -2,7 +2,6 @@ from dataclasses import dataclass import json -import logging import shutil import subprocess import time @@ -10,8 +9,7 @@ from urllib.error import URLError from urllib.request import urlopen - -LOG = logging.getLogger("deepseek_cursor_proxy") +from .logging import LOG DEFAULT_NGROK_API_URL = "http://127.0.0.1:4040/api" diff --git a/tests/test_server.py b/tests/test_server.py index 5c16cf6..87e8604 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -26,12 +26,14 @@ from urllib.request import Request, urlopen from deepseek_cursor_proxy.config import ProxyConfig +from deepseek_cursor_proxy.logging import ( + ConsoleLogFormatter, + TerminalSpinner, +) from deepseek_cursor_proxy.reasoning_store import ReasoningStore from deepseek_cursor_proxy.server import ( - ConsoleLogFormatter, DeepSeekProxyHandler, DeepSeekProxyServer, - TerminalSpinner, build_arg_parser, read_response_body, summarize_chat_payload, From 30310858c01ccc43042b5588a6c220c8a099430a Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 19:27:50 +0800 Subject: [PATCH 6/8] refactor(server): simplify logging --- src/deepseek_cursor_proxy/server.py | 18 ++++++++---- tests/test_server.py | 44 +++++++++++++++++++++++++++-- 2 files changed, 54 insertions(+), 8 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index eedd5e0..1a5b384 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -237,7 +237,8 @@ def do_POST(self) -> None: headers=upstream_headers, ) - log_send_summary(prepared) + if self.config.verbose: + log_send_summary(prepared) spinner = TerminalSpinner( enabled=bool(prepared.payload.get("stream")) and not self.config.verbose, text="└ {frame}", @@ -1011,22 +1012,27 @@ def log_cursor_request( ) -> None: model = str(payload.get("model") or config.upstream_model) LOG.info( - "┌ cursor model=%s effort=%s messages=%s tools=%s", + "┌ request model=%s effort=%s messages=%s", model, config.reasoning_effort, format_count(message_count(payload)), - format_count(tool_count(payload)), ) def log_context_summary(prepared: Any) -> None: + status = context_status(prepared) + if status == "ok": + LOG.info( + "├ context status=ok reasoning=%s", + format_count(prepared.patched_reasoning_messages), + ) + return LOG.info( - "├ context filled=%s missing=%s recovered=%s dropped=%s status=%s", - format_count(prepared.patched_reasoning_messages), + "├ context status=%s missing=%s recovered=%s dropped=%s", + status, format_count(prepared.missing_reasoning_messages), format_count(prepared.recovered_reasoning_messages), format_count(prepared.recovery_dropped_messages), - context_status(prepared), ) diff --git a/tests/test_server.py b/tests/test_server.py index 87e8604..00bce27 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -35,6 +35,7 @@ DeepSeekProxyHandler, DeepSeekProxyServer, build_arg_parser, + log_context_summary, read_response_body, summarize_chat_payload, ) @@ -234,6 +235,43 @@ def test_summarize_chat_payload_omits_message_content(self) -> None: self.assertIn("messages=1", summary) self.assertNotIn("secret prompt", summary) + def test_context_summary_keeps_default_ok_path_compact(self) -> None: + prepared = SimpleNamespace( + patched_reasoning_messages=53, + missing_reasoning_messages=0, + recovered_reasoning_messages=0, + recovery_dropped_messages=0, + ) + + with self.assertLogs("deepseek_cursor_proxy", level="INFO") as captured: + log_context_summary(prepared) + + self.assertEqual( + captured.output, + ["INFO:deepseek_cursor_proxy:├ context status=ok reasoning=53"], + ) + + def test_context_summary_expands_abnormal_path(self) -> None: + prepared = SimpleNamespace( + patched_reasoning_messages=53, + missing_reasoning_messages=0, + recovered_reasoning_messages=1, + recovery_dropped_messages=2, + ) + + with self.assertLogs("deepseek_cursor_proxy", level="INFO") as captured: + log_context_summary(prepared) + + self.assertEqual( + captured.output, + [ + ( + "INFO:deepseek_cursor_proxy:" + "├ context status=recovered missing=0 recovered=1 dropped=2" + ) + ], + ) + # --------------------------------------------------------------------------- # Client-disconnect / upstream-failure stubs (no real HTTP needed) @@ -553,9 +591,11 @@ def test_normal_logging_summarizes_without_bodies_or_keys(self) -> None: output = "\n".join(captured.output) self.assertEqual(status, 200) # Single-line stage records keep the log readable. - for marker in ("┌ cursor", "├ context", "├ send", "└ stats"): + for marker in ("┌ request", "├ context", "└ stats"): self.assertIn(marker, output) - self.assertNotIn("hi", output.split("┌ cursor")[1].split("\n")[0]) + self.assertNotIn(" tools=", output) + self.assertNotIn("├ send", output) + self.assertNotIn("hi", output.split("┌ request")[1].split("\n")[0]) self.assertNotIn("sk-from-cursor", output) def test_verbose_logging_includes_bodies_but_redacts_api_key(self) -> None: From ed1885ba4704339f23f762fb46ae3508f06d6974 Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 19:30:11 +0800 Subject: [PATCH 7/8] test(test_server): drop log_context_summary tests --- tests/test_server.py | 44 +++----------------------------------------- 1 file changed, 3 insertions(+), 41 deletions(-) diff --git a/tests/test_server.py b/tests/test_server.py index 00bce27..cdf5eb7 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -35,7 +35,6 @@ DeepSeekProxyHandler, DeepSeekProxyServer, build_arg_parser, - log_context_summary, read_response_body, summarize_chat_payload, ) @@ -235,43 +234,6 @@ def test_summarize_chat_payload_omits_message_content(self) -> None: self.assertIn("messages=1", summary) self.assertNotIn("secret prompt", summary) - def test_context_summary_keeps_default_ok_path_compact(self) -> None: - prepared = SimpleNamespace( - patched_reasoning_messages=53, - missing_reasoning_messages=0, - recovered_reasoning_messages=0, - recovery_dropped_messages=0, - ) - - with self.assertLogs("deepseek_cursor_proxy", level="INFO") as captured: - log_context_summary(prepared) - - self.assertEqual( - captured.output, - ["INFO:deepseek_cursor_proxy:├ context status=ok reasoning=53"], - ) - - def test_context_summary_expands_abnormal_path(self) -> None: - prepared = SimpleNamespace( - patched_reasoning_messages=53, - missing_reasoning_messages=0, - recovered_reasoning_messages=1, - recovery_dropped_messages=2, - ) - - with self.assertLogs("deepseek_cursor_proxy", level="INFO") as captured: - log_context_summary(prepared) - - self.assertEqual( - captured.output, - [ - ( - "INFO:deepseek_cursor_proxy:" - "├ context status=recovered missing=0 recovered=1 dropped=2" - ) - ], - ) - # --------------------------------------------------------------------------- # Client-disconnect / upstream-failure stubs (no real HTTP needed) @@ -590,9 +552,9 @@ def test_normal_logging_summarizes_without_bodies_or_keys(self) -> None: time.sleep(0.01) output = "\n".join(captured.output) self.assertEqual(status, 200) - # Single-line stage records keep the log readable. - for marker in ("┌ request", "├ context", "└ stats"): - self.assertIn(marker, output) + self.assertIn("┌ request model=deepseek-v4-pro effort=max messages=1", output) + self.assertIn("├ context status=ok reasoning=0", output) + self.assertIn("└ stats", output) self.assertNotIn(" tools=", output) self.assertNotIn("├ send", output) self.assertNotIn("hi", output.split("┌ request")[1].split("\n")[0]) From 4cbd1c4689537d892e53faf5060f6d804e7811de Mon Sep 17 00:00:00 2001 From: Yixing Lao Date: Mon, 4 May 2026 19:32:43 +0800 Subject: [PATCH 8/8] refactor(logging): rename reasoning log field --- src/deepseek_cursor_proxy/server.py | 2 +- tests/test_server.py | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/deepseek_cursor_proxy/server.py b/src/deepseek_cursor_proxy/server.py index 1a5b384..2594689 100644 --- a/src/deepseek_cursor_proxy/server.py +++ b/src/deepseek_cursor_proxy/server.py @@ -1023,7 +1023,7 @@ def log_context_summary(prepared: Any) -> None: status = context_status(prepared) if status == "ok": LOG.info( - "├ context status=ok reasoning=%s", + "├ context status=ok reasoning_context=%s", format_count(prepared.patched_reasoning_messages), ) return diff --git a/tests/test_server.py b/tests/test_server.py index cdf5eb7..b898aa8 100644 --- a/tests/test_server.py +++ b/tests/test_server.py @@ -553,7 +553,7 @@ def test_normal_logging_summarizes_without_bodies_or_keys(self) -> None: output = "\n".join(captured.output) self.assertEqual(status, 200) self.assertIn("┌ request model=deepseek-v4-pro effort=max messages=1", output) - self.assertIn("├ context status=ok reasoning=0", output) + self.assertIn("├ context status=ok reasoning_context=0", output) self.assertIn("└ stats", output) self.assertNotIn(" tools=", output) self.assertNotIn("├ send", output)