From 3e5f0016e3ed5df3604f488b776190bb95c91c02 Mon Sep 17 00:00:00 2001 From: jdmeyer3 Date: Thu, 17 Oct 2019 10:11:14 -0600 Subject: [PATCH 1/9] fixing subprocess to use system buffer instead of being unbuffered --- st2common/st2common/util/green/shell.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/st2common/st2common/util/green/shell.py b/st2common/st2common/util/green/shell.py index fe286f07eb..0eda39b88a 100644 --- a/st2common/st2common/util/green/shell.py +++ b/st2common/st2common/util/green/shell.py @@ -107,7 +107,7 @@ def run_command(cmd, stdin=None, stdout=subprocess.PIPE, stderr=subprocess.PIPE, # GreenPipe so it doesn't block LOG.debug('Creating subprocess.') process = concurrency.subprocess_popen(args=cmd, stdin=stdin, stdout=stdout, stderr=stderr, - env=env, cwd=cwd, shell=shell, preexec_fn=preexec_func) + env=env, cwd=cwd, shell=shell, preexec_fn=preexec_func, bufsize=-1) if read_stdout_func: LOG.debug('Spawning read_stdout_func function') From 25ea404641d80b5e49243fbf6635ddea81407b64 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 15:57:37 +0100 Subject: [PATCH 2/9] Allow user to pass "bufsize" argument to st2common.util.green.shell.run_command() function. --- st2common/st2common/util/green/shell.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/st2common/st2common/util/green/shell.py b/st2common/st2common/util/green/shell.py index 0eda39b88a..d126675251 100644 --- a/st2common/st2common/util/green/shell.py +++ b/st2common/st2common/util/green/shell.py @@ -38,7 +38,8 @@ def run_command(cmd, stdin=None, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=False, cwd=None, env=None, timeout=60, preexec_func=None, kill_func=None, read_stdout_func=None, read_stderr_func=None, - read_stdout_buffer=None, read_stderr_buffer=None, stdin_value=None): + read_stdout_buffer=None, read_stderr_buffer=None, stdin_value=None, + bufsize=0): """ Run the provided command in a subprocess and wait until it completes. @@ -82,6 +83,8 @@ def run_command(cmd, stdin=None, stdout=subprocess.PIPE, stderr=subprocess.PIPE, using live read mode. :type read_stdout_func: ``func`` + :param bufsize: Buffer size argument to pass to subprocess.popen function. + :type bufsize: ``int`` :rtype: ``tuple`` (exit_code, stdout, stderr, timed_out) """ @@ -107,7 +110,8 @@ def run_command(cmd, stdin=None, stdout=subprocess.PIPE, stderr=subprocess.PIPE, # GreenPipe so it doesn't block LOG.debug('Creating subprocess.') process = concurrency.subprocess_popen(args=cmd, stdin=stdin, stdout=stdout, stderr=stderr, - env=env, cwd=cwd, shell=shell, preexec_fn=preexec_func, bufsize=-1) + env=env, cwd=cwd, shell=shell, preexec_fn=preexec_func, + bufsize=bufsize) if read_stdout_func: LOG.debug('Spawning read_stdout_func function') From 2f96d5db92ac270932cfa648acdda049e8b1cfe0 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 16:16:27 +0100 Subject: [PATCH 3/9] Add new actionrunner.stream_output_buf_size config option and use that value for "bufsize" argument inside the Python runner run_command function call. For performance reasons, default it to -1, but allow users to change it via config if they are experiencing performance or similar issues. --- .../python_runner/python_runner/python_runner.py | 10 +++++++--- st2common/st2common/config.py | 8 +++++++- 2 files changed, 14 insertions(+), 4 deletions(-) diff --git a/contrib/runners/python_runner/python_runner/python_runner.py b/contrib/runners/python_runner/python_runner/python_runner.py index a1f42101b0..dae67f33e2 100644 --- a/contrib/runners/python_runner/python_runner/python_runner.py +++ b/contrib/runners/python_runner/python_runner/python_runner.py @@ -248,8 +248,11 @@ def run(self, action_parameters): if stdin_params: command_string = 'echo %s | %s' % (quote_unix(stdin_params), command_string) - LOG.debug('Running command: PATH=%s PYTHONPATH=%s %s' % (env['PATH'], env['PYTHONPATH'], - command_string)) + bufsize = cfg.CONF.actionrunner.stream_output_buffer_size + + LOG.debug('Running command (bufsize=%s): PATH=%s PYTHONPATH=%s %s' % (bufsize, env['PATH'], + env['PYTHONPATH'], + command_string)) exit_code, stdout, stderr, timed_out = run_command(cmd=args, stdin=stdin, stdout=subprocess.PIPE, @@ -261,7 +264,8 @@ def run(self, action_parameters): read_stderr_func=read_and_store_stderr, read_stdout_buffer=stdout, read_stderr_buffer=stderr, - stdin_value=stdin_params) + stdin_value=stdin_params, + bufsize=bufsize) LOG.debug('Returning values: %s, %s, %s, %s', exit_code, stdout, stderr, timed_out) LOG.debug('Returning.') return self._get_output_values(exit_code, stdout, stderr, timed_out) diff --git a/st2common/st2common/config.py b/st2common/st2common/config.py index 1b31b93e77..3bbd5725c1 100644 --- a/st2common/st2common/config.py +++ b/st2common/st2common/config.py @@ -376,7 +376,13 @@ def register_opts(ignore_errors=False): 'creates pack virtualenv.'), cfg.BoolOpt( 'stream_output', default=True, - help='True to store and stream action output (stdout and stderr) in real-time.') + help='True to store and stream action output (stdout and stderr) in real-time.'), + cfg.IntOpt( + 'stream_output_buffer_size', default=-1, + help=('Buffer size to use for real time action output streaming. 0 means unbuffered ' + '1 means line buffered, -1 means system default, which usually means fully ' + 'buffered and any other positive value means use a buffer of (approximately) ' + 'that size')) ] do_register_opts(action_runner_opts, group='actionrunner') From 711436fc167e4e209e0f5fda0b490b6f7e964c29 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 16:19:45 +0100 Subject: [PATCH 4/9] Add a simple test case which verifies that different values for "bufsize" argument don't hang or block the Python action runner streaming output functionality. --- .../tests/unit/test_pythonrunner.py | 32 +++++++++++++++++++ .../packs/pythonactions/actions/pascal_row.py | 2 ++ 2 files changed, 34 insertions(+) diff --git a/contrib/runners/python_runner/tests/unit/test_pythonrunner.py b/contrib/runners/python_runner/tests/unit/test_pythonrunner.py index 9c242f237f..407af29c60 100644 --- a/contrib/runners/python_runner/tests/unit/test_pythonrunner.py +++ b/contrib/runners/python_runner/tests/unit/test_pythonrunner.py @@ -406,6 +406,38 @@ def test_action_stdout_and_stderr_is_stored_in_the_db(self, mock_spawn, mock_pop self.assertEqual(output_dbs[1].data, mock_stderr[1]) self.assertEqual(output_dbs[2].data, mock_stderr[2]) + def test_real_time_output_streaming_bufsize(self): + # Test various values for bufsize and verify it works / doesn't hang the process + cfg.CONF.set_override(name='stream_output', group='actionrunner', override=True) + + bufsize_values = [-100, -2, -1, 0, 1, 2, 1024, 2048, 4096, 10000] + + for index, bufsize in enumerate(bufsize_values, 1): + cfg.CONF.set_override(name='stream_output_buffer_size', override=bufsize, + group='actionrunner') + + output_dbs = ActionExecutionOutput.get_all() + self.assertEqual(len(output_dbs), (index - 1) * 3) + + runner = self._get_mock_runner_obj() + runner.runner_parameters = {'log_level': 'INFO'} + runner.entry_point = PASCAL_ROW_ACTION_PATH + runner.pre_run() + (_, output, _) = runner.run({'row_index': 2}) + + expected_stderr = ''.join([ + 'st2.actions.python.PascalRowAction: INFO test info log message\n', + 'st2.actions.python.PascalRowAction: ERROR test error log message\n' + ]) + + self.assertEqual(output['stdout'], 'Pascal row action\n') + self.assertEqual(output['stderr'], expected_stderr) + self.assertEqual(output['result'], [1, 2, 1]) + self.assertEqual(output['exit_code'], 0) + + output_dbs = ActionExecutionOutput.get_all() + self.assertEqual(len(output_dbs), (index) * 3) + @mock.patch('st2common.util.concurrency.subprocess_popen') def test_stdout_interception_and_parsing(self, mock_popen): values = {'delimiter': ACTION_OUTPUT_RESULT_DELIMITER} diff --git a/st2tests/st2tests/resources/packs/pythonactions/actions/pascal_row.py b/st2tests/st2tests/resources/packs/pythonactions/actions/pascal_row.py index 6f42b63042..030670452b 100644 --- a/st2tests/st2tests/resources/packs/pythonactions/actions/pascal_row.py +++ b/st2tests/st2tests/resources/packs/pythonactions/actions/pascal_row.py @@ -36,6 +36,8 @@ def run(self, **kwargs): @staticmethod def _compute_pascal_row(row_index=0): + print('Pascal row action') + if row_index == 'a': return False, 'This is suppose to fail don\'t worry!!' elif row_index == 'b': From f058a5d1e36cb901f6fd57759ce5926cdcfde245 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 16:28:42 +0100 Subject: [PATCH 5/9] Add changelog entry. --- CHANGELOG.rst | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.rst b/CHANGELOG.rst index 6d79ce87f8..7199e85d5e 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -28,6 +28,12 @@ Changed writing very large executions (executions with large results) to the database. #4767 * Improved development instructions in requirements.txt and dist_utils.py comment headers (improvement) #4774 +* Add new ``actionrunner.stream_output_buffer_size`` config option and default it to ``-1`` + (previously default value was ``0``). This should result in a better performance and smaller + CPU utilization for Python runner actions which produce a lot of output. + (improvement) + + Reported and contributed by Joshua Meyer (@jdmeyer3) #4803 Fixed ~~~~~ From e7d62d1e07102c6d78151eb6c0121042cda81fc1 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 19:34:53 +0100 Subject: [PATCH 6/9] Re-generate sample config. --- conf/st2.conf.sample | 2 ++ 1 file changed, 2 insertions(+) diff --git a/conf/st2.conf.sample b/conf/st2.conf.sample index d5d295d058..b3a7262a46 100644 --- a/conf/st2.conf.sample +++ b/conf/st2.conf.sample @@ -20,6 +20,8 @@ python3_prefix = None virtualenv_binary = /usr/bin/virtualenv # Python 3 binary which will be used by Python actions for packs which use Python 3 virtual environment. python3_binary = /usr/bin/python3 +# Buffer size to use for real time action output streaming. 0 means unbuffered 1 means line buffered, -1 means system default, which usually means fully buffered and any other positive value means use a buffer of (approximately) that size +stream_output_buffer_size = -1 # List of virtualenv options to be passsed to "virtualenv" command that creates pack virtualenv. virtualenv_opts = --system-site-packages # comma separated list allowed here. # True to store and stream action output (stdout and stderr) in real-time. From e446a46a26eb7b3288fe34e9424e229b42998589 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 19:43:34 +0100 Subject: [PATCH 7/9] Use a separate action for bufsize test case. --- .../tests/unit/test_pythonrunner.py | 21 +++++--------- .../actions/print_to_stdout_and_stderr.py | 29 +++++++++++++++++++ 2 files changed, 37 insertions(+), 13 deletions(-) create mode 100644 st2tests/st2tests/resources/packs/pythonactions/actions/print_to_stdout_and_stderr.py diff --git a/contrib/runners/python_runner/tests/unit/test_pythonrunner.py b/contrib/runners/python_runner/tests/unit/test_pythonrunner.py index 407af29c60..7dcad87d28 100644 --- a/contrib/runners/python_runner/tests/unit/test_pythonrunner.py +++ b/contrib/runners/python_runner/tests/unit/test_pythonrunner.py @@ -63,6 +63,8 @@ PRINT_CONFIG_ITEM_ACTION = os.path.join(tests_base.get_resources_path(), 'packs', 'pythonactions/actions/print_config_item_doesnt_exist.py') +PRINT_TO_STDOUT_STDERR_ACTION = os.path.join(tests_base.get_resources_path(), 'packs', + 'pythonactions/actions/print_to_stdout_and_stderr.py') # Note: runner inherits parent args which doesn't work with tests since test pass additional @@ -417,26 +419,19 @@ def test_real_time_output_streaming_bufsize(self): group='actionrunner') output_dbs = ActionExecutionOutput.get_all() - self.assertEqual(len(output_dbs), (index - 1) * 3) + self.assertEqual(len(output_dbs), (index - 1) * 4) runner = self._get_mock_runner_obj() - runner.runner_parameters = {'log_level': 'INFO'} - runner.entry_point = PASCAL_ROW_ACTION_PATH + runner.entry_point = PRINT_TO_STDOUT_STDERR_ACTION runner.pre_run() - (_, output, _) = runner.run({'row_index': 2}) + (_, output, _) = runner.run({'stdout_count': 2, 'stderr_count': 2}) - expected_stderr = ''.join([ - 'st2.actions.python.PascalRowAction: INFO test info log message\n', - 'st2.actions.python.PascalRowAction: ERROR test error log message\n' - ]) - - self.assertEqual(output['stdout'], 'Pascal row action\n') - self.assertEqual(output['stderr'], expected_stderr) - self.assertEqual(output['result'], [1, 2, 1]) + self.assertEqual(output['stdout'], 'stdout line 0\nstdout line 1\n') + self.assertEqual(output['stderr'], 'stderr line 0\nstderr line 1\n') self.assertEqual(output['exit_code'], 0) output_dbs = ActionExecutionOutput.get_all() - self.assertEqual(len(output_dbs), (index) * 3) + self.assertEqual(len(output_dbs), (index) * 4) @mock.patch('st2common.util.concurrency.subprocess_popen') def test_stdout_interception_and_parsing(self, mock_popen): diff --git a/st2tests/st2tests/resources/packs/pythonactions/actions/print_to_stdout_and_stderr.py b/st2tests/st2tests/resources/packs/pythonactions/actions/print_to_stdout_and_stderr.py new file mode 100644 index 0000000000..7c7a044748 --- /dev/null +++ b/st2tests/st2tests/resources/packs/pythonactions/actions/print_to_stdout_and_stderr.py @@ -0,0 +1,29 @@ +# Copyright 2019 Extreme Networks, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +from __future__ import absolute_import + +import sys + +from st2common.runners.base_action import Action +from six.moves import range + + +class PrintToStdoutAndStderrAction(Action): + def run(self, stdout_count=3, stderr_count=3): + for index in range(0, stdout_count): + sys.stdout.write('stdout line %s\n' % (index)) + + for index in range(0, stderr_count): + sys.stderr.write('stderr line %s\n' % (index)) From 0b76bd505e0801bdf3e403c795dcbb84d5e0bf79 Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 20:30:07 +0100 Subject: [PATCH 8/9] Store log files for each screen session inside launchdev script. This way we can troubleshoot various "fail to start" issues on CI. Without this change, we have no visibility if service fails to start before the actual service starts writting into it's own log file. Sadly we can't rely on new version of screen which supports -Logfile path.log flag so we need to use screen config per screen window so we can use different log files for different processes. --- scripts/travis/prepare-integration.sh | 8 ++++ tools/launchdev.sh | 40 ++++++++++--------- tools/screen-configs/st2actionrunner.conf | 6 +++ tools/screen-configs/st2api.conf | 6 +++ tools/screen-configs/st2auth.conf | 6 +++ tools/screen-configs/st2garbagecollector.conf | 6 +++ tools/screen-configs/st2notifier.conf | 6 +++ tools/screen-configs/st2resultstracker.conf | 6 +++ tools/screen-configs/st2rulesengine.conf | 6 +++ tools/screen-configs/st2scheduler.conf | 6 +++ tools/screen-configs/st2sensorcontainer.conf | 6 +++ tools/screen-configs/st2stream.conf | 6 +++ tools/screen-configs/st2timersengine.conf | 6 +++ tools/screen-configs/st2workflowengine.conf | 6 +++ 14 files changed, 101 insertions(+), 19 deletions(-) create mode 100644 tools/screen-configs/st2actionrunner.conf create mode 100644 tools/screen-configs/st2api.conf create mode 100644 tools/screen-configs/st2auth.conf create mode 100644 tools/screen-configs/st2garbagecollector.conf create mode 100644 tools/screen-configs/st2notifier.conf create mode 100644 tools/screen-configs/st2resultstracker.conf create mode 100644 tools/screen-configs/st2rulesengine.conf create mode 100644 tools/screen-configs/st2scheduler.conf create mode 100644 tools/screen-configs/st2sensorcontainer.conf create mode 100644 tools/screen-configs/st2stream.conf create mode 100644 tools/screen-configs/st2timersengine.conf create mode 100644 tools/screen-configs/st2workflowengine.conf diff --git a/scripts/travis/prepare-integration.sh b/scripts/travis/prepare-integration.sh index deb77d620f..c20e1b5fde 100755 --- a/scripts/travis/prepare-integration.sh +++ b/scripts/travis/prepare-integration.sh @@ -15,9 +15,17 @@ source ./virtualenv/bin/activate python ./st2client/setup.py develop st2 --version +# Clean up old screen log files +rm -f logs/screen-*.log + # start dev environment in screens ./tools/launchdev.sh start -x +# Give processes some time to start and check logs to see if all the services +# started or if there was any error / failure +sleep 10 +cat logs/screen-*.log + # This script runs as root on Travis which means other processes which don't run # as root can't write to logs/ directory and tests fail chmod 777 logs/ diff --git a/tools/launchdev.sh b/tools/launchdev.sh index 5cc6b13899..ad2e5d9dec 100755 --- a/tools/launchdev.sh +++ b/tools/launchdev.sh @@ -245,15 +245,18 @@ function st2start(){ screen -ls | grep mistral | cut -d. -f1 | awk '{print $1}' | xargs kill fi + # NOTE: We can't rely on latest version of screen with "-Logfile path" + # option so we need to use screen config file per screen window + # Run the st2 API server echo 'Starting screen session st2-api...' if [ "${use_gunicorn}" = true ]; then echo ' using gunicorn to run st2-api...' export ST2_CONFIG_PATH=${ST2_CONF} - screen -d -m -S st2-api ${VIRTUALENV}/bin/gunicorn \ + screen -L -c tools/screen-configs/st2api.conf -d -m -S st2-api ${VIRTUALENV}/bin/gunicorn \ st2api.wsgi:application -k eventlet -b "$BINDING_ADDRESS:9101" --workers 1 else - screen -d -m -S st2-api ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2api.conf -d -m -S st2-api ${VIRTUALENV}/bin/python \ ./st2api/bin/st2api \ --config-file $ST2_CONF fi @@ -262,10 +265,10 @@ function st2start(){ if [ "${use_gunicorn}" = true ]; then echo ' using gunicorn to run st2-stream' export ST2_CONFIG_PATH=${ST2_CONF} - screen -d -m -S st2-stream ${VIRTUALENV}/bin/gunicorn \ + screen -L -c tools/screen-configs/st2stream.conf -d -m -S st2-stream ${VIRTUALENV}/bin/gunicorn \ st2stream.wsgi:application -k eventlet -b "$BINDING_ADDRESS:9102" --workers 1 else - screen -d -m -S st2-stream ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2stream.conf -d -m -S st2-stream ${VIRTUALENV}/bin/python \ ./st2stream/bin/st2stream \ --config-file $ST2_CONF fi @@ -278,7 +281,7 @@ function st2start(){ WORKFLOW_ENGINE_NAME=st2-workflow-$i WORKFLOW_ENGINE_SCREENS+=($WORKFLOW_ENGINE_NAME) echo ' starting '$WORKFLOW_ENGINE_NAME'...' - screen -d -m -S $WORKFLOW_ENGINE_NAME ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2workflowengine.conf -d -m -S $WORKFLOW_ENGINE_NAME ${VIRTUALENV}/bin/python \ ./st2actions/bin/st2workflowengine \ --config-file $ST2_CONF done @@ -291,14 +294,14 @@ function st2start(){ RUNNER_NAME=st2-actionrunner-$i RUNNER_SCREENS+=($RUNNER_NAME) echo ' starting '$RUNNER_NAME'...' - screen -d -m -S $RUNNER_NAME ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2actionrunner.conf -d -m -S $RUNNER_NAME ${VIRTUALENV}/bin/python \ ./st2actions/bin/st2actionrunner \ --config-file $ST2_CONF done # Run the garbage collector service echo 'Starting screen session st2-garbagecollector' - screen -d -m -S st2-garbagecollector ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2garbagecollector.conf -d -m -S st2-garbagecollector ${VIRTUALENV}/bin/python \ ./st2reactor/bin/st2garbagecollector \ --config-file $ST2_CONF @@ -310,38 +313,38 @@ function st2start(){ SCHEDULER_NAME=st2-scheduler-$i SCHEDULER_SCREENS+=($SCHEDULER_NAME) echo ' starting '$SCHEDULER_NAME'...' - screen -d -m -S $SCHEDULER_NAME ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2scheduler.conf -d -m -S $SCHEDULER_NAME ${VIRTUALENV}/bin/python \ ./st2actions/bin/st2scheduler \ --config-file $ST2_CONF done # Run the sensor container server echo 'Starting screen session st2-sensorcontainer' - screen -d -m -S st2-sensorcontainer ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2sensorcontainer.conf -d -m -S st2-sensorcontainer ${VIRTUALENV}/bin/python \ ./st2reactor/bin/st2sensorcontainer \ --config-file $ST2_CONF # Run the rules engine server echo 'Starting screen session st2-rulesengine...' - screen -d -m -S st2-rulesengine ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2rulesengine.conf -d -m -S st2-rulesengine ${VIRTUALENV}/bin/python \ ./st2reactor/bin/st2rulesengine \ --config-file $ST2_CONF # Run the timer engine server echo 'Starting screen session st2-timersengine...' - screen -d -m -S st2-timersengine ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2timersengine.conf -d -m -S st2-timersengine ${VIRTUALENV}/bin/python \ ./st2reactor/bin/st2timersengine \ --config-file $ST2_CONF # Run the results tracker echo 'Starting screen session st2-resultstracker...' - screen -d -m -S st2-resultstracker ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2resultstracker.conf -d -m -S st2-resultstracker ${VIRTUALENV}/bin/python \ ./st2actions/bin/st2resultstracker \ --config-file $ST2_CONF # Run the actions notifier echo 'Starting screen session st2-notifier...' - screen -d -m -S st2-notifier ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2notifier.conf -d -m -S st2-notifier ${VIRTUALENV}/bin/python \ ./st2actions/bin/st2notifier \ --config-file $ST2_CONF @@ -350,10 +353,10 @@ function st2start(){ if [ "${use_gunicorn}" = true ]; then echo ' using gunicorn to run st2-auth...' export ST2_CONFIG_PATH=${ST2_CONF} - screen -d -m -S st2-auth ${VIRTUALENV}/bin/gunicorn \ + screen -L -c tools/screen-configs/st2auth.conf -d -m -S st2-auth ${VIRTUALENV}/bin/gunicorn \ st2auth.wsgi:application -k eventlet -b "$BINDING_ADDRESS:9100" --workers 1 else - screen -d -m -S st2-auth ${VIRTUALENV}/bin/python \ + screen -L -c tools/screen-configs/st2auth.conf -d -m -S st2-auth ${VIRTUALENV}/bin/python \ ./st2auth/bin/st2auth \ --config-file $ST2_CONF fi @@ -364,18 +367,17 @@ function st2start(){ sudo mkdir -p $EXPORTS_DIR sudo chown -R ${CURRENT_USER}:${CURRENT_USER_GROUP} $EXPORTS_DIR echo 'Starting screen session st2-exporter...' - screen -d -m -S st2-exporter ${VIRTUALENV}/bin/python \ + screen -L -d -m -S st2-exporter ${VIRTUALENV}/bin/python \ ./st2exporter/bin/st2exporter \ --config-file $ST2_CONF fi if [ "${include_mistral}" = true ]; then - LOGDIR=${ST2_REPO}/logs # Run mistral-server echo 'Starting screen session mistral-server...' - screen -d -m -S mistral-server ${MISTRAL_REPO}/.venv/bin/python \ + screen -L -Logfile logs/screen-mistral-server.log -d -m -S mistral-server ${MISTRAL_REPO}/.venv/bin/python \ ${MISTRAL_REPO}/.venv/bin/mistral-server \ --server engine,executor \ --config-file $MISTRAL_CONF \ @@ -383,7 +385,7 @@ function st2start(){ # Run mistral-api echo 'Starting screen session mistral-api...' - screen -d -m -S mistral-api ${MISTRAL_REPO}/.venv/bin/python \ + screen -L -Logfile logs/screen-mistral-server.log -d -m -S mistral-api ${MISTRAL_REPO}/.venv/bin/python \ ${MISTRAL_REPO}/.venv/bin/mistral-server \ --server api \ --config-file $MISTRAL_CONF \ diff --git a/tools/screen-configs/st2actionrunner.conf b/tools/screen-configs/st2actionrunner.conf new file mode 100644 index 0000000000..c7c8d900a1 --- /dev/null +++ b/tools/screen-configs/st2actionrunner.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2actionrunner.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2api.conf b/tools/screen-configs/st2api.conf new file mode 100644 index 0000000000..834313114b --- /dev/null +++ b/tools/screen-configs/st2api.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2api.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2auth.conf b/tools/screen-configs/st2auth.conf new file mode 100644 index 0000000000..0bff41afcb --- /dev/null +++ b/tools/screen-configs/st2auth.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2auth.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2garbagecollector.conf b/tools/screen-configs/st2garbagecollector.conf new file mode 100644 index 0000000000..dddb0f68f4 --- /dev/null +++ b/tools/screen-configs/st2garbagecollector.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2garbagecollector.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2notifier.conf b/tools/screen-configs/st2notifier.conf new file mode 100644 index 0000000000..104d873a39 --- /dev/null +++ b/tools/screen-configs/st2notifier.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2notifier.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2resultstracker.conf b/tools/screen-configs/st2resultstracker.conf new file mode 100644 index 0000000000..c5d454d4d0 --- /dev/null +++ b/tools/screen-configs/st2resultstracker.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2resultstracker.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2rulesengine.conf b/tools/screen-configs/st2rulesengine.conf new file mode 100644 index 0000000000..1fca4d9807 --- /dev/null +++ b/tools/screen-configs/st2rulesengine.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2rulesengine.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2scheduler.conf b/tools/screen-configs/st2scheduler.conf new file mode 100644 index 0000000000..1bbcbd81f6 --- /dev/null +++ b/tools/screen-configs/st2scheduler.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2scheduler.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2sensorcontainer.conf b/tools/screen-configs/st2sensorcontainer.conf new file mode 100644 index 0000000000..735550d07b --- /dev/null +++ b/tools/screen-configs/st2sensorcontainer.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2sensorcontainer.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2stream.conf b/tools/screen-configs/st2stream.conf new file mode 100644 index 0000000000..e6c6b8c09e --- /dev/null +++ b/tools/screen-configs/st2stream.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2stream.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2timersengine.conf b/tools/screen-configs/st2timersengine.conf new file mode 100644 index 0000000000..5d358d8fec --- /dev/null +++ b/tools/screen-configs/st2timersengine.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2timersengine.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on diff --git a/tools/screen-configs/st2workflowengine.conf b/tools/screen-configs/st2workflowengine.conf new file mode 100644 index 0000000000..28d110e29c --- /dev/null +++ b/tools/screen-configs/st2workflowengine.conf @@ -0,0 +1,6 @@ +logfile logs/screen-st2workflowengine.log +logfile flush 1 +log on +logtstamp after 1 +logtstamp string \"[ %t: %Y-%m-%d %c:%s ]\012\" +logtstamp on From b3d885ab9b34d4270ff7cd75fa99f3e5ddce405a Mon Sep 17 00:00:00 2001 From: Tomaz Muraus Date: Tue, 29 Oct 2019 20:40:36 +0100 Subject: [PATCH 9/9] Add some log messages to make it easier to identify output. --- scripts/travis/prepare-integration.sh | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/scripts/travis/prepare-integration.sh b/scripts/travis/prepare-integration.sh index c20e1b5fde..3557ce398e 100755 --- a/scripts/travis/prepare-integration.sh +++ b/scripts/travis/prepare-integration.sh @@ -23,8 +23,12 @@ rm -f logs/screen-*.log # Give processes some time to start and check logs to see if all the services # started or if there was any error / failure +echo "Giving screen processes some time to start..." sleep 10 + +echo " === START: Catting screen process log files. ===" cat logs/screen-*.log +echo " === END: Catting screen process log files. ===" # This script runs as root on Travis which means other processes which don't run # as root can't write to logs/ directory and tests fail