diff --git a/bigchaindb/commands/bigchain.py b/bigchaindb/commands/bigchain.py index 767f6ccc..be17d75f 100644 --- a/bigchaindb/commands/bigchain.py +++ b/bigchaindb/commands/bigchain.py @@ -24,7 +24,8 @@ from bigchaindb.commands.messages import ( CANNOT_START_KEYPAIR_NOT_FOUND, RETHINKDB_STARTUP_ERROR, ) -from bigchaindb.commands.utils import configure_bigchaindb, input_on_stderr +from bigchaindb.commands.utils import ( + configure_bigchaindb, start_logging_process, input_on_stderr) logging.basicConfig(level=logging.INFO) @@ -169,6 +170,7 @@ def run_drop(args): @configure_bigchaindb +@start_logging_process def run_start(args): """Start the processes to run the node""" logger.info('BigchainDB Version %s', bigchaindb.__version__) diff --git a/bigchaindb/commands/utils.py b/bigchaindb/commands/utils.py index 73313f05..f4a311fa 100644 --- a/bigchaindb/commands/utils.py +++ b/bigchaindb/commands/utils.py @@ -21,20 +21,56 @@ from bigchaindb.version import __version__ def configure_bigchaindb(command): + """Decorator to be used by command line functions, such that the + configuration of bigchaindb is performed before the execution of + the command. + + Args: + command: The command to decorate. + + Returns: + The command wrapper function. + + """ @functools.wraps(command) def configure(args): - bigchaindb.config_utils.autoconfigure(filename=args.config, force=True) - - logging_config = bigchaindb.config['log'] or {} - if 'log_level' in args and args.log_level: - logging_config['level_console'] = args.log_level - setup_logging(user_log_config=logging_config) - + try: + config_from_cmdline = {'log': {'level_console': args.log_level}} + except AttributeError: + config_from_cmdline = None + bigchaindb.config_utils.autoconfigure( + filename=args.config, config=config_from_cmdline, force=True) command(args) return configure +def start_logging_process(command): + """Decorator to start the logging subscriber process. + + Args: + command: The command to decorate. + + Returns: + The command wrapper function. + + .. important:: + + Configuration, if needed, should be applied before invoking this + decorator, as starting the subscriber process for logging will + configure the root logger for the child process based on the + state of :obj:`bigchaindb.config` at the moment this decorator + is invoked. + + """ + @functools.wraps(command) + def start_logging(args): + from bigchaindb import config + setup_logging(user_log_config=config.get('log')) + command(args) + return start_logging + + # We need this because `input` always prints on stdout, while it should print # to stderr. It's a very old bug, check it out here: # - https://bugs.python.org/issue1927 diff --git a/tests/commands/rethinkdb/test_commands.py b/tests/commands/rethinkdb/test_commands.py index ac100075..165fef0d 100644 --- a/tests/commands/rethinkdb/test_commands.py +++ b/tests/commands/rethinkdb/test_commands.py @@ -38,7 +38,7 @@ def test_start_rethinkdb_exits_when_cannot_start(mock_popen): @patch('rethinkdb.ast.Table.reconfigure') -def test_set_shards(mock_reconfigure, monkeypatch, b, mocked_setup_logging): +def test_set_shards(mock_reconfigure, monkeypatch, b): from bigchaindb.commands.bigchain import run_set_shards # this will mock the call to retrieve the database config @@ -50,8 +50,6 @@ def test_set_shards(mock_reconfigure, monkeypatch, b, mocked_setup_logging): args = Namespace(num_shards=3, config=None) run_set_shards(args) mock_reconfigure.assert_called_with(replicas=1, shards=3, dry_run=False) - mocked_setup_logging.assert_called_once_with(user_log_config={}) - mocked_setup_logging.reset_mock() # this will mock the call to retrieve the database config # we will set it to return three replica @@ -61,10 +59,9 @@ def test_set_shards(mock_reconfigure, monkeypatch, b, mocked_setup_logging): monkeypatch.setattr(rethinkdb.RqlQuery, 'run', mockreturn_three_replicas) run_set_shards(args) mock_reconfigure.assert_called_with(replicas=3, shards=3, dry_run=False) - mocked_setup_logging.assert_called_once_with(user_log_config={}) -def test_set_shards_raises_exception(monkeypatch, b, mocked_setup_logging): +def test_set_shards_raises_exception(monkeypatch, b): from bigchaindb.commands.bigchain import run_set_shards # test that we are correctly catching the exception @@ -81,11 +78,10 @@ def test_set_shards_raises_exception(monkeypatch, b, mocked_setup_logging): with pytest.raises(SystemExit) as exc: run_set_shards(args) assert exc.value.args == ('Failed to reconfigure tables.',) - mocked_setup_logging.assert_called_once_with(user_log_config={}) @patch('rethinkdb.ast.Table.reconfigure') -def test_set_replicas(mock_reconfigure, monkeypatch, b, mocked_setup_logging): +def test_set_replicas(mock_reconfigure, monkeypatch, b): from bigchaindb.commands.bigchain import run_set_replicas # this will mock the call to retrieve the database config @@ -97,8 +93,6 @@ def test_set_replicas(mock_reconfigure, monkeypatch, b, mocked_setup_logging): args = Namespace(num_replicas=2, config=None) run_set_replicas(args) mock_reconfigure.assert_called_with(replicas=2, shards=2, dry_run=False) - mocked_setup_logging.assert_called_once_with(user_log_config={}) - mocked_setup_logging.reset_mock() # this will mock the call to retrieve the database config # we will set it to return three shards @@ -108,10 +102,9 @@ def test_set_replicas(mock_reconfigure, monkeypatch, b, mocked_setup_logging): monkeypatch.setattr(rethinkdb.RqlQuery, 'run', mockreturn_three_shards) run_set_replicas(args) mock_reconfigure.assert_called_with(replicas=2, shards=3, dry_run=False) - mocked_setup_logging.assert_called_once_with(user_log_config={}) -def test_set_replicas_raises_exception(monkeypatch, b, mocked_setup_logging): +def test_set_replicas_raises_exception(monkeypatch, b): from bigchaindb.commands.bigchain import run_set_replicas # test that we are correctly catching the exception @@ -128,4 +121,3 @@ def test_set_replicas_raises_exception(monkeypatch, b, mocked_setup_logging): with pytest.raises(SystemExit) as exc: run_set_replicas(args) assert exc.value.args == ('Failed to reconfigure tables.',) - mocked_setup_logging.assert_called_once_with(user_log_config={}) diff --git a/tests/commands/test_commands.py b/tests/commands/test_commands.py index eebd86ea..50b995b0 100644 --- a/tests/commands/test_commands.py +++ b/tests/commands/test_commands.py @@ -74,7 +74,7 @@ def test_bigchain_run_start_assume_yes_create_default_config( # interfere with capsys. # See related issue: https://github.com/pytest-dev/pytest/issues/128 @pytest.mark.usefixtures('ignore_local_config_file') -def test_bigchain_show_config(capsys, mocked_setup_logging): +def test_bigchain_show_config(capsys): from bigchaindb import config from bigchaindb.commands.bigchain import run_show_config @@ -85,11 +85,9 @@ def test_bigchain_show_config(capsys, mocked_setup_logging): del config['CONFIGURED'] config['keypair']['private'] = 'x' * 45 assert output_config == config - mocked_setup_logging.assert_called_once_with(user_log_config={}) -def test_bigchain_export_my_pubkey_when_pubkey_set(capsys, monkeypatch, - mocked_setup_logging): +def test_bigchain_export_my_pubkey_when_pubkey_set(capsys, monkeypatch): from bigchaindb import config from bigchaindb.commands.bigchain import run_export_my_pubkey @@ -106,11 +104,9 @@ def test_bigchain_export_my_pubkey_when_pubkey_set(capsys, monkeypatch, lines = out.splitlines() assert config['keypair']['public'] in lines assert 'Charlie_Bucket' in lines - mocked_setup_logging.assert_called_once_with(user_log_config={}) -def test_bigchain_export_my_pubkey_when_pubkey_not_set(monkeypatch, - mocked_setup_logging): +def test_bigchain_export_my_pubkey_when_pubkey_not_set(monkeypatch): from bigchaindb import config from bigchaindb.commands.bigchain import run_export_my_pubkey @@ -126,49 +122,41 @@ def test_bigchain_export_my_pubkey_when_pubkey_not_set(monkeypatch, # https://docs.python.org/3/library/exceptions.html#SystemExit assert exc_info.value.code == \ "This node's public key wasn't set anywhere so it can't be exported" - mocked_setup_logging.assert_called_once_with(user_log_config={}) -def test_bigchain_run_init_when_db_exists(mocked_setup_logging, - mock_db_init_with_existing_db): +def test_bigchain_run_init_when_db_exists(mock_db_init_with_existing_db): from bigchaindb.commands.bigchain import run_init args = Namespace(config=None) run_init(args) - mocked_setup_logging.assert_called_once_with(user_log_config={}) @patch('bigchaindb.backend.schema.drop_database') -def test_drop_db_when_assumed_yes(mock_db_drop, mocked_setup_logging): +def test_drop_db_when_assumed_yes(mock_db_drop): from bigchaindb.commands.bigchain import run_drop args = Namespace(config=None, yes=True) run_drop(args) assert mock_db_drop.called - mocked_setup_logging.assert_called_once_with(user_log_config={}) @patch('bigchaindb.backend.schema.drop_database') -def test_drop_db_when_interactive_yes(mock_db_drop, monkeypatch, - mocked_setup_logging): +def test_drop_db_when_interactive_yes(mock_db_drop, monkeypatch): from bigchaindb.commands.bigchain import run_drop args = Namespace(config=None, yes=False) monkeypatch.setattr('bigchaindb.commands.bigchain.input_on_stderr', lambda x: 'y') run_drop(args) assert mock_db_drop.called - mocked_setup_logging.assert_called_once_with(user_log_config={}) @patch('bigchaindb.backend.schema.drop_database') -def test_drop_db_does_not_drop_when_interactive_no(mock_db_drop, monkeypatch, - mocked_setup_logging): +def test_drop_db_does_not_drop_when_interactive_no(mock_db_drop, monkeypatch): from bigchaindb.commands.bigchain import run_drop args = Namespace(config=None, yes=False) monkeypatch.setattr('bigchaindb.commands.bigchain.input_on_stderr', lambda x: 'n') run_drop(args) assert not mock_db_drop.called - mocked_setup_logging.assert_called_once_with(user_log_config={}) def test_run_configure_when_config_exists_and_skipping(monkeypatch): @@ -417,7 +405,7 @@ def test_calling_main(start_mock, base_parser_mock, parse_args_mock, @pytest.mark.usefixtures('ignore_local_config_file') @patch('bigchaindb.commands.bigchain.add_replicas') -def test_run_add_replicas(mock_add_replicas, mocked_setup_logging): +def test_run_add_replicas(mock_add_replicas): from bigchaindb.commands.bigchain import run_add_replicas from bigchaindb.backend.exceptions import OperationError @@ -427,9 +415,7 @@ def test_run_add_replicas(mock_add_replicas, mocked_setup_logging): mock_add_replicas.return_value = None assert run_add_replicas(args) is None assert mock_add_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) mock_add_replicas.reset_mock() - mocked_setup_logging.reset_mock() # test add_replicas with `OperationError` mock_add_replicas.side_effect = OperationError('err') @@ -437,9 +423,7 @@ def test_run_add_replicas(mock_add_replicas, mocked_setup_logging): run_add_replicas(args) assert exc.value.args == ('err',) assert mock_add_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) mock_add_replicas.reset_mock() - mocked_setup_logging.reset_mock() # test add_replicas with `NotImplementedError` mock_add_replicas.side_effect = NotImplementedError('err') @@ -447,14 +431,12 @@ def test_run_add_replicas(mock_add_replicas, mocked_setup_logging): run_add_replicas(args) assert exc.value.args == ('err',) assert mock_add_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) mock_add_replicas.reset_mock() - mocked_setup_logging.reset_mock() @pytest.mark.usefixtures('ignore_local_config_file') @patch('bigchaindb.commands.bigchain.remove_replicas') -def test_run_remove_replicas(mock_remove_replicas, mocked_setup_logging): +def test_run_remove_replicas(mock_remove_replicas): from bigchaindb.commands.bigchain import run_remove_replicas from bigchaindb.backend.exceptions import OperationError @@ -464,8 +446,6 @@ def test_run_remove_replicas(mock_remove_replicas, mocked_setup_logging): mock_remove_replicas.return_value = None assert run_remove_replicas(args) is None assert mock_remove_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) - mocked_setup_logging.reset_mock() mock_remove_replicas.reset_mock() # test add_replicas with `OperationError` @@ -474,8 +454,6 @@ def test_run_remove_replicas(mock_remove_replicas, mocked_setup_logging): run_remove_replicas(args) assert exc.value.args == ('err',) assert mock_remove_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) - mocked_setup_logging.reset_mock() mock_remove_replicas.reset_mock() # test add_replicas with `NotImplementedError` @@ -484,6 +462,4 @@ def test_run_remove_replicas(mock_remove_replicas, mocked_setup_logging): run_remove_replicas(args) assert exc.value.args == ('err',) assert mock_remove_replicas.call_count == 1 - mocked_setup_logging.assert_called_once_with(user_log_config={}) - mocked_setup_logging.reset_mock() mock_remove_replicas.reset_mock() diff --git a/tests/commands/test_utils.py b/tests/commands/test_utils.py index 223c1f99..5f190717 100644 --- a/tests/commands/test_utils.py +++ b/tests/commands/test_utils.py @@ -1,7 +1,6 @@ import argparse from argparse import ArgumentTypeError, Namespace import logging -from logging import getLogger import pytest @@ -15,7 +14,7 @@ def reset_bigchaindb_config(monkeypatch): @pytest.mark.usefixtures('ignore_local_config_file', 'reset_bigchaindb_config') -def test_configure_bigchaindb_configures_bigchaindb(mocked_setup_logging): +def test_configure_bigchaindb_configures_bigchaindb(): from bigchaindb.commands.utils import configure_bigchaindb from bigchaindb.config_utils import is_configured assert not is_configured() @@ -26,7 +25,6 @@ def test_configure_bigchaindb_configures_bigchaindb(mocked_setup_logging): args = Namespace(config=None) test_configure(args) - mocked_setup_logging.assert_called_once_with(user_log_config={}) @pytest.mark.usefixtures('ignore_local_config_file', @@ -39,22 +37,19 @@ def test_configure_bigchaindb_configures_bigchaindb(mocked_setup_logging): logging.ERROR, logging.CRITICAL, )) -def test_configure_bigchaindb_configures_logging(log_level, - mocked_setup_sub_logger): +def test_configure_bigchaindb_logging(log_level): from bigchaindb.commands.utils import configure_bigchaindb - from bigchaindb.log.configs import PUBLISHER_LOGGING_CONFIG - root_logger = getLogger() - assert root_logger.level == logging.NOTSET + from bigchaindb import config + assert not config['log'] @configure_bigchaindb def test_configure_logger(args): - root_logger = getLogger() - assert root_logger.level == PUBLISHER_LOGGING_CONFIG['root']['level'] + pass args = Namespace(config=None, log_level=log_level) test_configure_logger(args) - mocked_setup_sub_logger.assert_called_once_with( - user_log_config={'level_console': log_level}) + from bigchaindb import config + assert config['log'] == {'level_console': log_level} def test_start_raises_if_command_not_implemented():