actions: Framework for capturing stdout/stderr in privileged daemon

Tests:

- If there is a syntax error in communication with privileged server. 'stdout'
and 'stderr' keys are present in 'exception' dictionary of the reply.

- If there is a error in the privileged method in communication with privileged
server. 'stdout' and 'stderr' keys are present in 'exception' dictionary of the
reply. The values are filled with output of the command that have been run.

- If a privileged method uses action_utils.run, then raising an exception in the
method shows proper stdout and stderr in the UI HTML message.

Signed-off-by: Sunil Mohan Adapa <sunil@medhas.org>
Reviewed-by: Joseph Nuthalapati <njoseph@riseup.net>

plinth/action_utils.py

@@ -13,6 +13,8 @@ from contextlib import contextmanager
 
 import augeas
 
+from . import actions
+
 logger = logging.getLogger(__name__)
 
 UWSGI_ENABLED_PATH = '/etc/uwsgi/apps-enabled/{config_name}.ini'
@@ -797,4 +799,25 @@ def run_as_user(command, username, **kwargs):
     setpriv. Sets real/effective uid/gid and resets the environment.
     """
     command = ['runuser', '--user', username, '--'] + command
-    return subprocess.run(command, **kwargs)
+    return run(command, **kwargs)
+
+
+def run(command, **kwargs):
+    """Run subprocess.run but capture stdout and stderr in thread storage."""
+    collect_stdout = ('stdout' not in kwargs)
+    collect_stderr = ('stderr' not in kwargs)
+
+    if collect_stdout:
+        kwargs['stdout'] = subprocess.PIPE
+
+    if collect_stderr:
+        kwargs['stderr'] = subprocess.PIPE
+
+    process = subprocess.run(command, **kwargs)
+    if collect_stdout and actions.thread_storage:
+        actions.thread_storage.stdout += process.stdout
+
+    if collect_stderr and actions.thread_storage:
+        actions.thread_storage.stderr += process.stderr
+
+    return process

plinth/actions.py

@@ -20,6 +20,8 @@ logger = logging.getLogger(__name__)
 
 socket_path = '/run/freedombox/privileged.socket'
 
+thread_storage = None
+
 
 # An alias for 'str' to mark some strings as sensitive. Sensitive strings are
 # not logged. Use 'type secret_str = str' when Python 3.11 support is no longer
@@ -165,8 +167,8 @@ def _wait_for_server_response(func, module_name, action_name, args, kwargs,
     module = importlib.import_module(return_value['exception']['module'])
     exception_class = getattr(module, return_value['exception']['name'])
     exception = exception_class(*return_value['exception']['args'])
-    exception.stdout = b''
-    exception.stderr = b''
+    exception.stdout = return_value['exception']['stdout'].encode()
+    exception.stderr = return_value['exception']['stderr'].encode()
 
     def _get_html_message():
         """Return an HTML format error that can be shown in messages."""
@@ -356,6 +358,47 @@ class JSONEncoder(json.JSONEncoder):
         return super().default(obj)
 
 
+def _setup_thread_storage():
+    """Setup collection of stdout/stderr from any process in this thread."""
+    global thread_storage
+    thread_storage = threading.local()
+    thread_storage.stdout = b''
+    thread_storage.stderr = b''
+
+
+def _clear_thread_storage():
+    """Cleanup memory used for stdout/stderr from processes in this thread.
+
+    Python documentation is silent on whether thread local storage will be
+    cleaned up after a thread terminates.
+    """
+    global thread_storage
+    if thread_storage:
+        thread_storage.stdout = None
+        thread_storage.stderr = None
+        thread_storage = None
+
+
+def get_return_value_from_exception(exception):
+    """Return the value to return from server when an exception is raised."""
+    return_value = {
+        'result': 'exception',
+        'exception': {
+            'module': type(exception).__module__,
+            'name': type(exception).__name__,
+            'args': exception.args,
+            'traceback': traceback.format_tb(exception.__traceback__),
+            'stdout': '',
+            'stderr': ''
+        }
+    }
+    if thread_storage:
+        return_value['exception']['stdout'] = thread_storage.stdout.decode()
+        return_value['exception']['stderr'] = thread_storage.stderr.decode()
+
+    return return_value
+
+
 def privileged_handle_json_request(
         request_string: str) -> str | io.BufferedReader:
     """Parse arguments for the program spawned as a privileged action."""
@@ -388,6 +431,7 @@ def privileged_handle_json_request(
         logger.info('Received request for %s..%s(..)', request['module'],
                     request['action'])
         arguments = {'args': request['args'], 'kwargs': request['kwargs']}
+        _setup_thread_storage()
         return_value = _privileged_call(request['module'], request['action'],
                                         arguments)
 
@@ -403,15 +447,9 @@ def privileged_handle_json_request(
         else:
             logger.exception(exception)
 
-        return_value = {
-            'result': 'exception',
-            'exception': {
-                'module': type(exception).__module__,
-                'name': type(exception).__name__,
-                'args': exception.args,
-                'traceback': traceback.format_tb(exception.__traceback__)
-            }
-        }
+        return_value = get_return_value_from_exception(exception)
+
+    _clear_thread_storage()
 
     return json.dumps(return_value, cls=JSONEncoder)
 
@@ -461,15 +499,7 @@ def _privileged_call(module_name, action_name, arguments):
 
         return_value = {'result': 'success', 'return': return_values}
     except Exception as exception:
-        return_value = {
-            'result': 'exception',
-            'exception': {
-                'module': type(exception).__module__,
-                'name': type(exception).__name__,
-                'args': exception.args,
-                'traceback': traceback.format_tb(exception.__traceback__)
-            }
-        }
+        return_value = get_return_value_from_exception(exception)
 
     return return_value
 

plinth/privileged_daemon.py

@@ -13,7 +13,6 @@ import socketserver
 import struct
 import sys
 import time
-import traceback
 
 import systemd.daemon
 
@@ -72,15 +71,7 @@ class RequestHandler(socketserver.StreamRequestHandler):
             response_string = actions.privileged_handle_json_request(request)
         except Exception as exception:
             logger.exception('Error running privileged request: %s', exception)
-            response = {
-                'result': 'exception',
-                'exception': {
-                    'module': type(exception).__module__,
-                    'name': type(exception).__name__,
-                    'args': exception.args,
-                    'traceback': traceback.format_tb(exception.__traceback__)
-                }
-            }
+            response = actions.get_return_value_from_exception(exception)
             response_string = json.dumps(response)
 
         self._write_response(response_string)

plinth/tests/test_action_utils.py

@@ -6,12 +6,12 @@ Test module for key/value store.
 import json
 import pathlib
 import subprocess
-from unittest.mock import call, patch
+from unittest.mock import Mock, call, patch
 
 import pytest
 
 from plinth.action_utils import (get_addresses, get_hostname,
-                                 is_systemd_running, move_uploaded_file,
+                                 is_systemd_running, move_uploaded_file, run,
                                  run_as_user, service_action, service_disable,
                                  service_enable, service_is_enabled,
                                  service_is_running, service_reload,
@@ -232,15 +232,69 @@ def test_move_uploaded_file(tmp_path, upload_dir):
 
 
 @patch('subprocess.run')
-def test_run_as_user(run):
+def test_run_as_user(subprocess_run):
     """Test running a command as another user works."""
-    run.return_value = 'test-return-value'
+    subprocess_run.return_value = 'test-return-value'
     return_value = run_as_user(['command', 'arg1', '--foo'],
                                username='foouser', stdout=subprocess.PIPE,
                                check=True)
     assert return_value == 'test-return-value'
-    assert run.mock_calls == [
+    assert subprocess_run.mock_calls == [
         call(
             ['runuser', '--user', 'foouser', '--', 'command', 'arg1', '--foo'],
-            stdout=subprocess.PIPE, check=True)
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE, check=True)
     ]
+
+
+@patch('plinth.actions.thread_storage')
+@patch('subprocess.run')
+def test_run_capture(subprocess_run, thread_storage):
+    """Test running a command with stdin/stdout capture works."""
+    thread_storage.stdout = 'initial-stdout'
+    thread_storage.stderr = 'initial-stderr'
+
+    subprocess_run.return_value = Mock()
+    subprocess_run.return_value.stdout = 'test-stdout'
+    subprocess_run.return_value.stderr = 'test-stderr'
+
+    return_value = run(['command', 'arg1', '--foo'], check=True)
+    assert return_value == subprocess_run.return_value
+    assert subprocess_run.mock_calls == [
+        call(['command', 'arg1', '--foo'], stdout=subprocess.PIPE,
+             stderr=subprocess.PIPE, check=True)
+    ]
+    assert thread_storage.stdout == 'initial-stdouttest-stdout'
+    assert thread_storage.stderr == 'initial-stderrtest-stderr'
+
+
+@patch('plinth.actions.thread_storage')
+@patch('subprocess.run')
+def test_run_no_capture(subprocess_run, thread_storage):
+    """Test running a command without stdin/stdout capture works."""
+    thread_storage.stdout = 'initial-stdout'
+    thread_storage.stderr = 'initial-stderr'
+
+    subprocess_run.return_value = Mock()
+    subprocess_run.return_value.stdout = 'test-stdout'
+    subprocess_run.return_value.stderr = 'test-stderr'
+
+    return_value = run(['command', 'arg1', '--foo'], stdout=subprocess.PIPE,
+                       stderr=subprocess.PIPE, check=True)
+    assert return_value == subprocess_run.return_value
+    assert subprocess_run.mock_calls == [
+        call(['command', 'arg1', '--foo'], stdout=subprocess.PIPE,
+             stderr=subprocess.PIPE, check=True)
+    ]
+    assert thread_storage.stdout == 'initial-stdout'
+    assert thread_storage.stderr == 'initial-stderr'
+
+
+@patch('plinth.actions.thread_storage', None)
+@patch('subprocess.run')
+def test_run_no_storage(subprocess_run):
+    """Test running a command without thread storage."""
+    subprocess_run.return_value = Mock()
+    subprocess_run.return_value.stdout = 'test-stdout'
+    subprocess_run.return_value.stderr = 'test-stderr'
+
+    run(['command', 'arg1', '--foo'], check=True)