Commit d69a48dd authored by Jérome Perrin's avatar Jérome Perrin

testnode: don't include distributor URL

These logs are public and the URL can include credentials.

Fixes #20200514-E3304
parent caab7974
...@@ -563,6 +563,49 @@ shared = true ...@@ -563,6 +563,49 @@ shared = true
test_node.purgeOldTestSuite(test_suite_data) # should not fail test_node.purgeOldTestSuite(test_suite_data) # should not fail
self.assertEqual([], os.listdir(self.working_directory)) self.assertEqual([], os.listdir(self.working_directory))
def test_distributor_url_obfuscated_in_logs(self):
test_node = self.getTestNode()
runner = test_type_registry['UnitTest'](test_node)
node_test_suite = test_node.getNodeTestSuite('foo')
self.updateNodeTestSuiteData(node_test_suite)
node_test_suite.revision_list = ('dummy', (0, '')),
path = runner.getInstanceRoot(node_test_suite) + '/a/bin/runTestSuite'
os.makedirs(os.path.dirname(path))
with tempfile.NamedTemporaryFile(mode='r') as temp_file:
with open(path, 'w') as f:
f.write("""#!/bin/sh
echo runTestSuite called with: "$@" | tee {}
""".format(temp_file.name))
os.chmod(path, 0o700)
with mock.patch.object(logger, '_log') as http_logger,\
mock.patch.object(logging.getLogger(), '_log') as root_logger,\
mock.patch.object(logging.getLogger(), 'isEnabledFor', return_value=True):
runner.runTestSuite(node_test_suite, "https://user:secret@example.com/portal_distributions")
http_logger.assert_called()
logged_messages = [str(logged) for logged in http_logger.mock_calls]
# distributor URL is not displayed in logs
self.assertFalse([m for m in logged_messages if "https://user:secret@example.com/portal_distributions" in m])
# instead we display obfuscated $DISTRIBUTOR_URL
self.assertTrue([m for m in logged_messages if "--master_url $DISTRIBUTOR_URL" in m])
# but the runTestSuite program is called with the actual distributor URL
self.assertEqual(
'runTestSuite called with: --master_url https://user:secret@example.com/portal_distributions'
' --revision dummy=0- --test_suite Foo --test_suite_title Foo-Test',
temp_file.read().strip())
# The root logger (which logs only in var/log/erp5testnode.log) contain the non obfuscated
# command, because it's sometimes useful for debugging.
root_logger.assert_called()
self.assertIn(
'--master_url https://user:secret@example.com/portal_distributions',
str(root_logger.mock_calls[-1]))
def test_09_runTestSuite(self, my_test_type='UnitTest'): def test_09_runTestSuite(self, my_test_type='UnitTest'):
""" """
Check parameters passed to runTestSuite Check parameters passed to runTestSuite
......
...@@ -68,7 +68,7 @@ def format_command(*args, **kw): ...@@ -68,7 +68,7 @@ def format_command(*args, **kw):
cmdline.append(v) cmdline.append(v)
return ' '.join(cmdline) return ' '.join(cmdline)
def subprocess_capture(p, log_prefix, get_output=True): def subprocess_capture(p, log_prefix, get_output=True, output_replacers=()):
log = logger.info log = logger.info
if log_prefix: if log_prefix:
log_prefix += ': ' log_prefix += ': '
...@@ -77,6 +77,8 @@ def subprocess_capture(p, log_prefix, get_output=True): ...@@ -77,6 +77,8 @@ def subprocess_capture(p, log_prefix, get_output=True):
data = input.readline() data = input.readline()
if not data: if not data:
break break
for replacer in output_replacers:
data = replacer(data)
if get_output: if get_output:
buffer.append(data) buffer.append(data)
log(log_prefix + (data if str is bytes else log(log_prefix + (data if str is bytes else
...@@ -158,6 +160,8 @@ class ProcessManager(object): ...@@ -158,6 +160,8 @@ class ProcessManager(object):
log_prefix = kw.pop('log_prefix', '') log_prefix = kw.pop('log_prefix', '')
new_session = kw.pop('new_session', True) new_session = kw.pop('new_session', True)
subprocess_kw = {} subprocess_kw = {}
output_replacers = kw.pop('output_replacers', ())
cwd = kw.pop('cwd', None) cwd = kw.pop('cwd', None)
if cwd: if cwd:
subprocess_kw['cwd'] = cwd subprocess_kw['cwd'] = cwd
...@@ -166,6 +170,9 @@ class ProcessManager(object): ...@@ -166,6 +170,9 @@ class ProcessManager(object):
raise_error_if_fail = kw.pop('raise_error_if_fail', True) raise_error_if_fail = kw.pop('raise_error_if_fail', True)
env = dict(os.environ, **kw) if kw else None env = dict(os.environ, **kw) if kw else None
command = format_command(*args, **kw) command = format_command(*args, **kw)
# obfuscate secrets from command, assuming command is utf-8
for replacer in output_replacers:
command = replacer(command.encode('utf-8')).decode('utf-8')
logger.info('subprocess_kw : %r', subprocess_kw) logger.info('subprocess_kw : %r', subprocess_kw)
logger.info('$ %s', command) logger.info('$ %s', command)
sys.stdout.flush() sys.stdout.flush()
...@@ -176,7 +183,7 @@ class ProcessManager(object): ...@@ -176,7 +183,7 @@ class ProcessManager(object):
timer = threading.Timer(self.max_timeout, timeoutExpired, args=(p,)) timer = threading.Timer(self.max_timeout, timeoutExpired, args=(p,))
self.timer_set.add(timer) self.timer_set.add(timer)
timer.start() timer.start()
stdout, stderr = subprocess_capture(p, log_prefix, get_output=get_output) stdout, stderr = subprocess_capture(p, log_prefix, get_output=get_output, output_replacers=output_replacers)
timer.cancel() timer.cancel()
self.timer_set.discard(timer) self.timer_set.discard(timer)
result = dict(status_code=p.returncode, command=command, result = dict(status_code=p.returncode, command=command,
......
...@@ -27,8 +27,10 @@ ...@@ -27,8 +27,10 @@
import os import os
import glob import glob
import json import json
import logging
from . import logger from . import logger
from .ProcessManager import SubprocessError from .ProcessManager import SubprocessError, format_command
from .SlapOSControler import SlapOSControler from .SlapOSControler import SlapOSControler
from .Utils import createFolder from .Utils import createFolder
from slapos.grid.utils import md5digest from slapos.grid.utils import md5digest
...@@ -180,9 +182,22 @@ class UnitTestRunner(object): ...@@ -180,9 +182,22 @@ class UnitTestRunner(object):
# result. We only do cleanup if the test runner itself is not able # result. We only do cleanup if the test runner itself is not able
# to run. # to run.
createFolder(node_test_suite.test_suite_directory, clean=True) createFolder(node_test_suite.test_suite_directory, clean=True)
# Log the actual command with root logger
root_logger = logging.getLogger()
root_logger.info(
"Running test suite with: %s",
format_command(*invocation_list, PATH=PATH))
def hide_distributor_url(s):
# type: (bytes) -> bytes
return s.replace(portal_url.encode('utf-8'), b'$DISTRIBUTOR_URL')
self.testnode.process_manager.spawn(*invocation_list, PATH=PATH, self.testnode.process_manager.spawn(*invocation_list, PATH=PATH,
cwd=node_test_suite.test_suite_directory, cwd=node_test_suite.test_suite_directory,
log_prefix='runTestSuite', get_output=False) log_prefix='runTestSuite',
output_replacers=(hide_distributor_url,),
get_output=False)
def getRelativePathUsage(self): def getRelativePathUsage(self):
""" """
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment