xml-rpc "tailProcessStdoutLog" is not safe.

[ita9naiwa]

I'm using 4.2.4 of Supervisor on aarm64 mac.

tailProcessStdoutLog produces UnicodeDecodeError sometimes.

server

2022-01-13 13:56:18,912 CRIT Handling XML-RPC request with data "<?xml version='1.0'?>\n<methodCall>\n<methodName>supervisor.tailProcessLog</methodName>\n<params>\n<param>\n<value><string>P1</string></value>\n</param>\n<param>\n<value><int>0</int></value>\n</param>\n<param>\n<value><int>1000</int></value>\n</param>\n</params>\n</methodCall>\n" raised an unexpected exception: Traceback (most recent call last):
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/xmlrpc.py", line 410, in continue_request
    value = self.call(method, params)
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/xmlrpc.py", line 446, in call
    return traverse(self.rpcinterface, method, params)
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/xmlrpc.py", line 469, in traverse
    return func(*params)
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/rpcinterface.py", line 774, in tailProcessStdoutLog
    return self._tailProcessLog(name, offset, length, 'stdout')
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/rpcinterface.py", line 752, in _tailProcessLog
    return tailFile(logfile, int(offset), int(length))
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/options.py", line 2136, in tailFile
    return [as_string(data), offset, overflow]
  File "/opt/homebrew/Cellar/supervisor/4.2.4/libexec/lib/python3.10/site-packages/supervisor/compat.py", line 60, in as_string
    return s.decode(encoding)
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x9c in position 0: invalid start byte

client

  File "/usr/lib/python3.9/xmlrpc/client.py", line 1160, in request
    return self.single_request(host, handler, request_body, verbose)
  File "/usr/lib/python3.9/xmlrpc/client.py", line 1190, in single_request
    raise ProtocolError(
xmlrpc.client.ProtocolError: <ProtocolError for [host]:23232/RPC2: 500 Internal Server Error>

When log contains UTF-8 character it causes error. I guess it is because cutting logs by the specified length of characters (e.g., 17) and it makes log cannot be decodable sometimes. since logs are cut by each byte.

[mnaberez]

When log contains utf-8 character it causes error.

Could you please provide more information to help reproduce this error? There are existing tests that exercise reading a log with UTF-8 characters already and they are passing. We need more information to be able to duplicate this issue, e.g. what exactly is in the log and what exact commands are run.

[ita9naiwa]

worker: tmp.py

import time
import logging
l = logging.Logger("a")
while True:
  l.warning("나뉸바보^_^")
  print(31434134)
  time.sleep(0.01)

supervisord config (conf.conf)

[supervisord]

[program:P1]
command=python tmp.py
directory = /Users/ita
stdout_logfile = ./log
stdout_logfile_maxbytes = 10MB
stdout_logfile_backups = 3
redirect_stderr = true

[supervisord]

[supervisorctl]

[inet_http_server]
port = 23233

[rpcinterface:supervisor]
supervisor.rpcinterface_factory = supervisor.rpcinterface:make_main_rpcinterface

on an shell, run this supervisord -n -c conf.conf

on another shell.

import xmlrpc.client
x = xmlrpc.client.ServerProxy("http://localhost:23233")
while True:
  a = x.supervisor.tailProcessLog('P1', 0, 17)  # it produces error soon.

I'm sorry I made a very verbose test.

[ita9naiwa]

@mnaberez Thanks for replying! the python script and supervisor server are run on python 3.9, and system encoding is "utf-8" I found no issues when I access Supervisor Server with HTTP socket, but I saw an error only with XML-RPC.

[mnaberez]

Thank you very much for the reproduce info!

[Chi-teck]

Getting same problem.

2023-11-08 03:55:15,690 CRIT Handling XML-RPC request with data '<?xml version="1.0" encoding="UTF-8"?><methodCall><methodName>supervisor.tailProcessStdoutLog</methodName><params><param><value><string>scanner:trips-03</string></value></param><param><value><int>0</int></value></param><param><value><int>10000</int></value></param></params></methodCall>' raised an unexpected exception: Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/supervisor/xmlrpc.py", line 410, in continue_request
    value = self.call(method, params)
            ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/xmlrpc.py", line 446, in call
    return traverse(self.rpcinterface, method, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/xmlrpc.py", line 469, in traverse
    return func(*params)
           ^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/rpcinterface.py", line 778, in tailProcessStdoutLog
    return self._tailProcessLog(name, offset, length, 'stdout')
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/rpcinterface.py", line 756, in _tailProcessLog
    return tailFile(logfile, int(offset), int(length))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/options.py", line 2132, in tailFile
    return [as_string(data), offset, overflow]
            ^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/supervisor/compat.py", line 60, in as_string
    return s.decode(encoding)
           ^^^^^^^^^^^^^^^^^^
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xb4 in position 0: invalid start byte

[sdebionne]

I get this error as well and wonder if this simple patch would fix it:

diff --git a/supervisor/options.py b/supervisor/options.py
index 0b26614..ed95ac9 100644
--- a/supervisor/options.py
+++ b/supervisor/options.py
@@ -2130,7 +2130,7 @@ def tailFile(filename, offset, length):
                 data = f.read(length)

             offset = sz
-            return [as_string(data), offset, overflow]
+            return [data.decode('ascii', 'ignore'), offset, overflow]
     except (OSError, IOError):
         return ['', offset, False]