diff --git a/bootstrap/bootstrap.py b/bootstrap/bootstrap.py index d1c961a..98e7245 100644 --- a/bootstrap/bootstrap.py +++ b/bootstrap/bootstrap.py @@ -18,6 +18,7 @@ import sys import logging import shutil +logger = logging.getLogger(__name__) def get_os_release_variable(key): """ @@ -32,6 +33,36 @@ def get_os_release_variable(key): "source /etc/os-release && echo ${{{key}}}".format(key=key) ]).decode().strip() +# Copied into tljh/utils.py. Make sure the copies are exactly the same! +def run_subprocess(cmd, *args, **kwargs): + """ + Run given cmd with smart output behavior. + + If command succeeds, print output to debug logging. + If it fails, print output to info logging. + + In TLJH, this sends successful output to the installer log, + and failed output directly to the user's screen + """ + logger = logging.getLogger('tljh') + proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, *args, **kwargs) + printable_command = ' '.join(cmd) + if proc.returncode != 0: + # Our process failed! Show output to the user + logger.error('Ran {command} with exit code {code}'.format( + command=printable_command, code=proc.returncode + )) + logger.error(proc.stdout.decode()) + raise subprocess.CalledProcessError(cmd=cmd, returncode=proc.returncode) + else: + # This goes into installer.log + logger.debug('Ran {command} with exit code {code}'.format( + command=printable_command, code=proc.returncode + )) + # This produces multi line log output, unfortunately. Not sure how to fix. + # For now, prioritizing human readability over machine readability. + logger.debug(proc.stdout.decode()) + def validate_host(): """ Make sure TLJH is installable in current host @@ -65,17 +96,21 @@ def main(): hub_prefix = os.path.join(install_prefix, 'hub') # Set up logging to print to a file and to stderr - logger = logging.getLogger(__name__) - os.makedirs(install_prefix, exist_ok=True) - file_logger = logging.FileHandler(os.path.join(install_prefix, 'installer.log')) + file_logger_path = os.path.join(install_prefix, 'installer.log') + file_logger = logging.FileHandler(file_logger_path) + # installer.log should be readable only by root + os.chmod(file_logger_path, 0o500) + file_logger.setFormatter(logging.Formatter('%(asctime)s %(message)s')) + file_logger.setLevel(logging.DEBUG) logger.addHandler(file_logger) stderr_logger = logging.StreamHandler() stderr_logger.setFormatter(logging.Formatter('%(message)s')) + stderr_logger.setLevel(logging.INFO) logger.addHandler(stderr_logger) - logger.setLevel(logging.INFO) + logger.setLevel(logging.DEBUG) logger.info('Checking if TLJH is already installed...') if os.path.exists(os.path.join(hub_prefix, 'bin', 'python3')): @@ -89,20 +124,20 @@ def main(): # that's where the python3-pip package lives. In some very minimal base # VM images, it looks like the universe repository is disabled by default, # causing bootstrapping to fail. - subprocess.check_output(['apt-get', 'update', '--yes'], stderr=subprocess.STDOUT) - subprocess.check_output(['apt-get', 'install', '--yes', 'software-properties-common'], stderr=subprocess.STDOUT) - subprocess.check_output(['add-apt-repository', 'universe'], stderr=subprocess.STDOUT) + run_subprocess(['apt-get', 'update', '--yes']) + run_subprocess(['apt-get', 'install', '--yes', 'software-properties-common']) + run_subprocess(['add-apt-repository', 'universe']) - subprocess.check_output(['apt-get', 'update', '--yes'], stderr=subprocess.STDOUT) - subprocess.check_output(['apt-get', 'install', '--yes', - 'git', + run_subprocess(['apt-get', 'update', '--yes']) + run_subprocess(['apt-get', 'install', '--yes', 'python3', 'python3-venv', - 'python3-pip' - ], stderr=subprocess.STDOUT) + 'python3-pip', + 'git' + ]) logger.info('Installed python & virtual environment') os.makedirs(hub_prefix, exist_ok=True) - subprocess.check_output(['python3', '-m', 'venv', hub_prefix], stderr=subprocess.STDOUT) + run_subprocess(['python3', '-m', 'venv', hub_prefix]) logger.info('Set up hub virtual environment') if initial_setup: @@ -118,10 +153,10 @@ def main(): 'git+https://github.com/jupyterhub/the-littlest-jupyterhub.git' ) - subprocess.check_output([ + run_subprocess([ os.path.join(hub_prefix, 'bin', 'pip'), 'install' - ] + pip_flags + [tljh_repo_path], stderr=subprocess.STDOUT) + ] + pip_flags + [tljh_repo_path]) logger.info('Setup tljh package') logger.info('Starting TLJH installer...') diff --git a/dev-requirements.txt b/dev-requirements.txt index 166dd49..6296fdd 100644 --- a/dev-requirements.txt +++ b/dev-requirements.txt @@ -1,4 +1,5 @@ pytest pytest-cov +pytest-mock codecov pytoml \ No newline at end of file diff --git a/integration-tests/test_install.py b/integration-tests/test_install.py index 1b27eea..d3aa712 100644 --- a/integration-tests/test_install.py +++ b/integration-tests/test_install.py @@ -117,6 +117,12 @@ def test_admin_writable(): permissions_test(ADMIN_GROUP, sys.prefix, writable=True, dirs_only=True) +def test_installer_log_readable(): + # Test that installer.log is owned by root, and not readable by anyone else + file_stat = os.stat('/opt/tljh/installer.log') + assert file_stat.st_uid == 0 + assert file_stat.st_mode == 0o100500 + @pytest.mark.parametrize("group", [ADMIN_GROUP, USER_GROUP]) def test_user_env_readable(group): # every file in user env should be readable by everyone diff --git a/tests/test_utils.py b/tests/test_utils.py new file mode 100644 index 0000000..b123c95 --- /dev/null +++ b/tests/test_utils.py @@ -0,0 +1,21 @@ +import pytest +from tljh import utils +import subprocess +import logging + + +def test_run_subprocess_exception(mocker): + logger = logging.getLogger('tljh') + mocker.patch.object(logger, 'error') + with pytest.raises(subprocess.CalledProcessError): + utils.run_subprocess( + ['/bin/bash', '-c', 'echo error; exit 1'] + ) + logger.error.assert_called_with('error\n') + + +def test_run_subprocess(mocker): + logger = logging.getLogger('tljh') + mocker.patch.object(logger, 'debug') + utils.run_subprocess(['/bin/bash', '-c', 'echo success']) + logger.debug.assert_called_with('success\n') \ No newline at end of file diff --git a/tljh/apt.py b/tljh/apt.py index fe8ddc0..d2c5fec 100644 --- a/tljh/apt.py +++ b/tljh/apt.py @@ -3,6 +3,7 @@ Utilities for working with the apt package manager """ import os import subprocess +from tljh import utils def trust_gpg_key(key): @@ -14,7 +15,7 @@ def trust_gpg_key(key): # If gpg2 doesn't exist, install it. if not os.path.exists('/usr/bin/gpg2'): install_packages(['gnupg2']) - subprocess.check_output(['apt-key', 'add', '-'], input=key, stderr=subprocess.STDOUT) + utils.run_subprocess(['apt-key', 'add', '-'], input=key) def add_source(name, source_url, section): @@ -32,7 +33,7 @@ def add_source(name, source_url, section): f.seek(0) f.write(line) f.truncate() - subprocess.check_output(['apt-get', 'update', '--yes'], stderr=subprocess.STDOUT) + utils.run_subprocess(['apt-get', 'update', '--yes']) def install_packages(packages): @@ -41,9 +42,9 @@ def install_packages(packages): """ # Check if an apt-get update is required if len(os.listdir('/var/lib/apt/lists')) == 0: - subprocess.check_output(['apt-get', 'update', '--yes'], stderr=subprocess.STDOUT) - subprocess.check_output([ + utils.run_subprocess(['apt-get', 'update', '--yes']) + utils.run_subprocess([ 'apt-get', 'install', '--yes' - ] + packages, stderr=subprocess.STDOUT) + ] + packages) diff --git a/tljh/conda.py b/tljh/conda.py index 35d45fc..ebd8d86 100644 --- a/tljh/conda.py +++ b/tljh/conda.py @@ -9,6 +9,7 @@ import contextlib import tempfile import requests from distutils.version import LooseVersion as V +from tljh import utils def md5_file(fname): @@ -68,22 +69,22 @@ def fix_permissions(prefix): Run after each install command. """ - subprocess.check_call( + utils.run_subprocess( ["chown", "-R", "{}:{}".format(os.getuid(), os.getgid()), prefix] ) - subprocess.check_call(["chmod", "-R", "o-w", prefix]) + utils.run_subprocess(["chmod", "-R", "o-w", prefix]) def install_miniconda(installer_path, prefix): """ Install miniconda with installer at installer_path under prefix """ - subprocess.check_output([ + utils.run_subprocess([ '/bin/bash', installer_path, '-u', '-b', '-p', prefix - ], stderr=subprocess.STDOUT) + ]) # fix permissions on initial install # a few files have the wrong ownership and permissions initially # when the installer is run as root @@ -128,10 +129,10 @@ def ensure_pip_packages(prefix, packages): abspath = os.path.abspath(prefix) pip_executable = [os.path.join(abspath, 'bin', 'python'), '-m', 'pip'] - subprocess.check_output(pip_executable + [ + utils.run_subprocess(pip_executable + [ 'install', '--no-cache-dir', - ] + packages, stderr=subprocess.STDOUT) + ] + packages) fix_permissions(prefix) @@ -144,9 +145,9 @@ def ensure_pip_requirements(prefix, requirements_path): abspath = os.path.abspath(prefix) pip_executable = [os.path.join(abspath, 'bin', 'python'), '-m', 'pip'] - subprocess.check_output(pip_executable + [ + utils.run_subprocess(pip_executable + [ 'install', '-r', requirements_path - ], stderr=subprocess.STDOUT) + ]) fix_permissions(prefix) diff --git a/tljh/installer.py b/tljh/installer.py index a0fc4e3..dd65671 100644 --- a/tljh/installer.py +++ b/tljh/installer.py @@ -22,6 +22,7 @@ from tljh import ( systemd, traefik, user, + utils ) from .config import ( CONFIG_DIR, @@ -35,7 +36,6 @@ from .yaml import yaml HERE = os.path.abspath(os.path.dirname(__file__)) - logger = logging.getLogger("tljh") def ensure_node(): @@ -172,7 +172,7 @@ def ensure_jupyterlab_extensions(): '@jupyterlab/hub-extension', '@jupyter-widgets/jupyterlab-manager' ] - subprocess.check_output([ + utils.run_subprocess([ os.path.join(USER_ENV_PREFIX, 'bin/jupyter'), 'labextension', 'install' diff --git a/tljh/utils.py b/tljh/utils.py new file mode 100644 index 0000000..395d395 --- /dev/null +++ b/tljh/utils.py @@ -0,0 +1,36 @@ +""" +Miscelaneous functions useful in at least two places unrelated to each other +""" +import subprocess +import logging + + +# Copied into bootstrap/bootstrap.py. Make sure these two copies are exactly the same! +def run_subprocess(cmd, *args, **kwargs): + """ + Run given cmd with smart output behavior. + + If command succeeds, print output to debug logging. + If it fails, print output to info logging. + + In TLJH, this sends successful output to the installer log, + and failed output directly to the user's screen + """ + logger = logging.getLogger('tljh') + proc = subprocess.run(cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, *args, **kwargs) + printable_command = ' '.join(cmd) + if proc.returncode != 0: + # Our process failed! Show output to the user + logger.error('Ran {command} with exit code {code}'.format( + command=printable_command, code=proc.returncode + )) + logger.error(proc.stdout.decode()) + raise subprocess.CalledProcessError(cmd=cmd, returncode=proc.returncode) + else: + # This goes into installer.log + logger.debug('Ran {command} with exit code {code}'.format( + command=printable_command, code=proc.returncode + )) + # This produces multi line log output, unfortunately. Not sure how to fix. + # For now, prioritizing human readability over machine readability. + logger.debug(proc.stdout.decode()) \ No newline at end of file