Fix WebSocket disconnect during large manual log file uploads (#1062)

app/test_engine/models/manual_test_case.py

@@ -35,6 +35,13 @@
 OUTCOME_TIMEOUT_S = 60 * 10  # Seconds
 LOG_UPLOAD_TIMEOUT_S = 60 * 10  # Seconds
 
+# Number of lines from an uploaded manual log to combine into a single log entry.
+# Uploaded logs can have hundreds of thousands of lines; logging (and therefore
+# broadcasting to the UI websocket and persisting to the DB) one entry per line
+# stalls the event loop for long enough that the websocket's keepalive ping/pong
+# times out and the connection is dropped (see GitHub issue #1062).
+MANUAL_LOG_CHUNK_LINES = 500
+
 
 class TestError(Exception):
     """Raised when an error occurs during execution."""
@@ -197,16 +204,28 @@ def handle_uploaded_file(self, file: UploadFile) -> None:
 
         logger.info(f"Uploading manual log: {file.filename}")
         logger.info("---- Start of Manual Log ----")
+        had_invalid_utf8 = False
         with file.file as f:
+            chunk: list[str] = []
             for line in f:
                 try:
-                    logger.info(line.decode("utf-8").strip())
+                    chunk.append(line.decode("utf-8").rstrip("\r\n"))
                 except UnicodeDecodeError:
-                    logger.warning(
-                        "WARNING: The following line contained invalid UTF-8."
-                        " Some content was replaced with: �"
-                    )
-                    logger.info(line.decode("utf-8", errors="replace").strip())
+                    had_invalid_utf8 = True
+                    chunk.append(line.decode("utf-8", errors="replace").rstrip("\r\n"))
+
+                if len(chunk) >= MANUAL_LOG_CHUNK_LINES:
+                    logger.info("\n".join(chunk))
+                    chunk = []
+
+            if chunk:
+                logger.info("\n".join(chunk))
+
+        if had_invalid_utf8:
+            logger.warning(
+                "WARNING: The uploaded log contained lines with invalid UTF-8."
+                " Some content was replaced with: �"
+            )
         logger.info("---- End of Manual Log ----")
 
 

app/tests/test_engine/test_manual_test_case.py

@@ -0,0 +1,121 @@
+#
+# Copyright (c) 2026 Project CHIP Authors
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+from io import BytesIO
+from typing import BinaryIO, Optional
+from unittest import mock
+
+from app.test_engine.models.manual_test_case import (
+    MANUAL_LOG_CHUNK_LINES,
+    ManualLogUploadStep,
+)
+
+
+class FakeUploadFile:
+    """Minimal stand-in for FastAPI's UploadFile used by handle_uploaded_file."""
+
+    def __init__(self, content: bytes, content_type: str = "text/plain") -> None:
+        self.file: BinaryIO = BytesIO(content)
+        self.filename: Optional[str] = "manual_log.txt"
+        self.content_type = content_type
+
+
+@mock.patch("app.test_engine.models.manual_test_case.logger")
+def test_handle_uploaded_file_rejects_unsupported_content_type(
+    mock_logger: mock.Mock,
+) -> None:
+    step = ManualLogUploadStep("Prompt Manual Log Upload")
+    step.append_failure = mock.Mock()  # type: ignore[method-assign]
+
+    step.handle_uploaded_file(FakeUploadFile(b"irrelevant", content_type="image/png"))
+
+    step.append_failure.assert_called_once()
+    mock_logger.info.assert_not_called()
+
+
+@mock.patch("app.test_engine.models.manual_test_case.logger")
+def test_handle_uploaded_file_batches_lines_into_chunks(mock_logger: mock.Mock) -> None:
+    """A large uploaded log must not result in one logger.info() call per line.
+
+    Regression test for GitHub issue #1062: logging one entry per line floods
+    the same channel used to broadcast updates over the websocket and to
+    persist to the DB, stalling the event loop long enough that the
+    websocket's ping/pong keepalive times out mid-upload.
+    """
+    line_count = MANUAL_LOG_CHUNK_LINES * 2 + 3
+    content = "\n".join(f"line-{i}" for i in range(line_count)).encode("utf-8")
+
+    step = ManualLogUploadStep("Prompt Manual Log Upload")
+    step.append_failure = mock.Mock()  # type: ignore[method-assign]
+
+    step.handle_uploaded_file(FakeUploadFile(content))
+
+    step.append_failure.assert_not_called()
+
+    # "Uploading manual log: ...", "---- Start ----", N chunk(s), "---- End ----"
+    info_calls = [call.args[0] for call in mock_logger.info.call_args_list]
+    assert info_calls[0].startswith("Uploading manual log:")
+    assert info_calls[1] == "---- Start of Manual Log ----"
+    assert info_calls[-1] == "---- End of Manual Log ----"
+
+    chunk_calls = info_calls[2:-1]
+    # 2 full chunks + 1 partial chunk, never one call per line.
+    assert len(chunk_calls) == 3
+    assert chunk_calls[0].count("\n") == MANUAL_LOG_CHUNK_LINES - 1
+    assert chunk_calls[-1].count("\n") == 2  # trailing partial chunk of 3 lines
+
+    # All lines are still present, in order, across the batched calls.
+    reconstructed = "\n".join(chunk_calls).splitlines()
+    assert reconstructed == [f"line-{i}" for i in range(line_count)]
+
+
+@mock.patch("app.test_engine.models.manual_test_case.logger")
+def test_handle_uploaded_file_replaces_invalid_utf8_and_warns_once(
+    mock_logger: mock.Mock,
+) -> None:
+    content = b"good line\n\xff\xfe bad line\ngood line 2\n"
+
+    step = ManualLogUploadStep("Prompt Manual Log Upload")
+    step.append_failure = mock.Mock()  # type: ignore[method-assign]
+
+    step.handle_uploaded_file(FakeUploadFile(content))
+
+    mock_logger.warning.assert_called_once()
+    info_calls = [call.args[0] for call in mock_logger.info.call_args_list]
+    body = "\n".join(info_calls[2:-1])
+    assert "�" in body
+
+
+@mock.patch("app.test_engine.models.manual_test_case.logger")
+def test_handle_uploaded_file_strips_windows_line_endings(
+    mock_logger: mock.Mock,
+) -> None:
+    """Windows-style CRLF line endings must not leave a stray \\r in each line.
+
+    Regression test: an earlier version of this fix used .rstrip("\\n"), which
+    left a trailing \\r on every line of a CRLF-terminated file, corrupting the
+    joined chunk with embedded carriage returns.
+    """
+    content = b"line one\r\nline two\r\nline three\r\n"
+
+    step = ManualLogUploadStep("Prompt Manual Log Upload")
+    step.append_failure = mock.Mock()  # type: ignore[method-assign]
+
+    step.handle_uploaded_file(FakeUploadFile(content))
+
+    info_calls = [call.args[0] for call in mock_logger.info.call_args_list]
+    body = "\n".join(info_calls[2:-1])
+    assert "\r" not in body
+    assert body.splitlines() == ["line one", "line two", "line three"]

app/uvicorn_worker.py

@@ -0,0 +1,38 @@
+#
+# Copyright (c) 2026 Project CHIP Authors
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+#
+"""Gunicorn worker class with a longer websocket ping timeout.
+
+Uploading a large manual test log (see GitHub issue #1062) can keep the event
+loop busy for an extended period (each uploaded line is turned into a log
+entry that gets broadcast over the same main websocket and persisted to the
+DB). With uvicorn's default ``ws_ping_timeout`` (20s), the websocket's
+keepalive ping/pong can't be serviced in time, causing the connection to be
+dropped mid-upload with `ConnectionClosedError: no close frame received or
+sent`.
+
+This mirrors the ``--ws-ping-timeout 60`` flag already used by the dev-only
+``gunicorn/start-reload.sh`` script, so production gets the same tolerance.
+"""
+from uvicorn.workers import UvicornWorker
+
+WS_PING_TIMEOUT_S = 60
+
+
+class ExtendedTimeoutUvicornWorker(UvicornWorker):
+    CONFIG_KWARGS = {
+        **UvicornWorker.CONFIG_KWARGS,
+        "ws_ping_timeout": WS_PING_TIMEOUT_S,
+    }

gunicorn/start.sh

@@ -40,7 +40,10 @@ else
     DEFAULT_GUNICORN_CONF=/gunicorn_conf.py
 fi
 export GUNICORN_CONF=${GUNICORN_CONF:-$DEFAULT_GUNICORN_CONF}
-export WORKER_CLASS=${WORKER_CLASS:-"uvicorn.workers.UvicornWorker"}
+# ExtendedTimeoutUvicornWorker raises ws_ping_timeout (default UvicornWorker: 20s).
+# Uploading a large manual test log can keep the event loop busy long enough for
+# the default timeout to drop the websocket mid-upload (issue #1062).
+export WORKER_CLASS=${WORKER_CLASS:-"app.uvicorn_worker.ExtendedTimeoutUvicornWorker"}
 
 # If there's a prestart.sh script in the /app directory or other path specified, run it before starting
 DEFAULT_PRE_START_PATH="/app/prestart.sh"