Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Provide much better error messages #337

Merged
merged 3 commits into from
May 29, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 50 additions & 15 deletions bootstrap/bootstrap.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
import logging
import shutil

logger = logging.getLogger(__name__)

def get_os_release_variable(key):
"""
Expand All @@ -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
Expand Down Expand Up @@ -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')):
Expand All @@ -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:
Expand All @@ -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...')
Expand Down
1 change: 1 addition & 0 deletions dev-requirements.txt
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
pytest
pytest-cov
pytest-mock
codecov
pytoml
6 changes: 6 additions & 0 deletions integration-tests/test_install.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
21 changes: 21 additions & 0 deletions tests/test_utils.py
Original file line number Diff line number Diff line change
@@ -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')
11 changes: 6 additions & 5 deletions tljh/apt.py
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
"""
import os
import subprocess
from tljh import utils


def trust_gpg_key(key):
Expand All @@ -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):
Expand All @@ -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):
Expand All @@ -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)
17 changes: 9 additions & 8 deletions tljh/conda.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import tempfile
import requests
from distutils.version import LooseVersion as V
from tljh import utils


def md5_file(fname):
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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)


Expand All @@ -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)
4 changes: 2 additions & 2 deletions tljh/installer.py
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
systemd,
traefik,
user,
utils
)
from .config import (
CONFIG_DIR,
Expand All @@ -33,7 +34,6 @@

HERE = os.path.abspath(os.path.dirname(__file__))


logger = logging.getLogger("tljh")

def ensure_node():
Expand Down Expand Up @@ -170,7 +170,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'
Expand Down
36 changes: 36 additions & 0 deletions tljh/utils.py
Original file line number Diff line number Diff line change
@@ -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())