Skip to content

Logging freeze with multi-byte characters in long output lines #1308

@sakamoto-sxd

Description

@sakamoto-sxd

Describe the bug
It seems that logging gets stuck when long lines contain multi-byte characters.

If you print a very long string that contain multi-byte characters without a new line in it in a container, podman-compose gets stuck and becomes unresponsive.
It will need keyboard interrupt or a kill.

To Reproduce
Steps to reproduce the behavior:

  1. Prepare this compose.yaml in a new directory:
services:
  s1:
    image: docker.io/python:3.11-slim
    command: python -c'print("あ" * 1000000 + " end")'
  1. Run podman-compose up.

Expected behavior
It prints a very long line of "あ あ あ ..." and exits.

Actual behavior
It gets stuck before printing anything. Ctrl-c will get you the output below.

Output

# podman-compose version
podman-compose version 1.5.0
podman version 4.9.4-rhel

podman-compose up and Ctrl-c after 1 second:

# podman-compose up
bc47bad90d0248df9454a04c102b89cc5fbcc929714d9c59eaabb23441a71d56
Trying to pull docker.io/library/python:3.11-slim...
Getting image source signatures
Copying blob 1961ca026b04 done   |
Copying blob fcec5a125fd8 done   |
Copying blob 396b1da7636e done   |
Copying blob a27cb4be7017 done   |
Copying config 2ba2e944f9 done   |
Writing manifest to image destination
6785b3b6c1e7311c67e83a3f610b7b0c30b90b9c329cada25a4c1aa3949d137a
^CError: timed out waiting for file /run/libpod/exits/6785b3b6c1e7311c67e83a3f610b7b0c30b90b9c329cada25a4c1aa3949d137a
test_s1_1
^C[s1] | time="2025-09-08T06:06:36Z" level=error msg="forwarding signal 2 to container 6785b3b6c1e7311c67e83a3f610b7b0c30b90b9c329cada25a4c1aa3949d137a: no container with ID 6785b3b6c1e7311c67e83a3f610b7b0c30b90b9c329cada25a4c1aa3949d137a found in database: no such container"
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-28' coro=<Podman._format_stream() done, defined at /usr/lib/python3.9/site-packages/podman_compose.py:1581> exception=UnicodeDecodeError('utf-8', b'\xe3\x81\x82\xe3\x81\x82\

: snip

\xe3\x81\x82\xe3\x81\x82\xe3\x81', 131070, 131072, 'unexpected end of data')>
Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/podman_compose.py", line 1608, in _format_stream
    _formatted_print_without_nl(part.decode())
UnicodeDecodeError: 'utf-8' codec can't decode bytes in position 131070-131071: unexpected end of data
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f9c21e2ed30>
Traceback (most recent call last):
  File "/usr/lib64/python3.9/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.9/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.9/asyncio/unix_events.py", line 536, in close
    self._close(None)
  File "/usr/lib64/python3.9/asyncio/unix_events.py", line 560, in _close
    self._loop.call_soon(self._call_connection_lost, exc)
  File "/usr/lib64/python3.9/asyncio/base_events.py", line 751, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.9/asyncio/base_events.py", line 515, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

Environment:

  • OS: Red Hat Enterprise Linux release 9.4 (Plow)
  • podman version: 4.9.4-rhel
  • podman compose version: 1.5.0

Additional context

This issue occurs when multi-byte characters are used.
Therefore, we suspect that the following issue, which was supposed to be fixed in podman-compose 1.3.0,
was not fixed with multi-byte characters in mind.

As a test, we found that the issue no longer occurred after modifying the following source code for podman-copose.

1581     async def _format_stream(
1582         self, reader: asyncio.StreamReader, sink: Any, log_formatter: str
1583     ) -> None:
1584         line_ongoing = False
1585
1586         def _formatted_print_with_nl(s: str) -> None:
1587             if line_ongoing:
1588                 print(s, file=sink, end="\n")
1589             else:
1590                 print(log_formatter, s, file=sink, end="\n")
1591
1592         def _formatted_print_without_nl(s: str) -> None:
1593             if line_ongoing:
1594                 print(s, file=sink, end="")
1595             else:
1596                 print(log_formatter, s, file=sink, end="")
1597
1598         decoder = codecs.getincrementaldecoder("utf-8")() # add
1599
1600         while not reader.at_eof():
1601             chunk = await self._readchunk(reader)
1602             parts = chunk.split(b"\n")
1603
1604             for i, part in enumerate(parts):
1605                 # Iff part is last and non-empty, we leave an ongoing line to be completed later
1606                 if i < len(parts) - 1:
1607                     _formatted_print_with_nl(decoder.decode(part)) # Changed to use getincrementaldecoder
1608                     line_ongoing = False
1609                 elif len(part) > 0:
1610                     _formatted_print_without_nl(decoder.decode(part)) # Changed to use getincrementaldecoder
1611                     line_ongoing = True
1612         if line_ongoing:
1613             # Make sure the last line ends with EOL
1614             print(file=sink, end="\n")

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions