Skip to content

Commit

Permalink
Bug 1941166 - handle long lines in pipe_to_log (#679)
Browse files Browse the repository at this point in the history
Avoid deadlock with full pipe buffer when the output contains long lines
(>64kB).  If we go this long without a newline, log what we have and
keep going.
  • Loading branch information
jcristau authored Jan 15, 2025
1 parent 83f13ab commit 8cf1190
Show file tree
Hide file tree
Showing 2 changed files with 23 additions and 1 deletion.
10 changes: 9 additions & 1 deletion src/scriptworker/log.py
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
log (logging.Logger): the log object for this module.
"""
import asyncio
import logging
import logging.handlers
import os
Expand Down Expand Up @@ -82,7 +83,14 @@ async def pipe_to_log(pipe: StreamReader, filehandles: Sequence[IO[str]] = (), l
"""
while True:
line = await pipe.readline() # type: Union[str, bytes]
try:
line = await pipe.readuntil() # type: Union[str, bytes]
except asyncio.exceptions.IncompleteReadError as e:
line = e.partial
except asyncio.exceptions.LimitOverrunError:
# line too long
line = bytes(pipe._buffer)
pipe._buffer.clear()
if line:
line = to_unicode(line)
log.log(level, line.rstrip())
Expand Down
14 changes: 14 additions & 0 deletions tests/test_log.py
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,20 @@ async def test_pipe_to_log(rw_context):
assert read(log_file) in ("foo\nbar\n", "bar\nfoo\n")


@pytest.mark.asyncio
async def test_pipe_to_log_limit(rw_context):
cmd = ["echo", "a" * 100_000]
proc = await asyncio.create_subprocess_exec(*cmd, stdout=PIPE, stderr=PIPE, stdin=None)
tasks = []
with swlog.get_log_filehandle(rw_context) as log_fh:
tasks.append(asyncio.create_task(swlog.pipe_to_log(proc.stderr, filehandles=[log_fh])))
tasks.append(asyncio.create_task(swlog.pipe_to_log(proc.stdout, filehandles=[log_fh])))
await asyncio.wait(tasks)
await proc.wait()
log_file = swlog.get_log_filename(rw_context)
assert len(read(log_file)) == 100_001


def test_update_logging_config_verbose(rw_context):
rw_context.config["verbose"] = True
swlog.update_logging_config(rw_context, log_name=rw_context.config["log_dir"])
Expand Down

0 comments on commit 8cf1190

Please sign in to comment.