diff --git a/bigchaindb/commands/bigchain.py b/bigchaindb/commands/bigchain.py index 62f3a7f6..767f6ccc 100644 --- a/bigchaindb/commands/bigchain.py +++ b/bigchaindb/commands/bigchain.py @@ -25,7 +25,6 @@ from bigchaindb.commands.messages import ( RETHINKDB_STARTUP_ERROR, ) from bigchaindb.commands.utils import configure_bigchaindb, input_on_stderr -from bigchaindb.log.setup import setup_logging logging.basicConfig(level=logging.INFO) @@ -174,9 +173,6 @@ def run_start(args): """Start the processes to run the node""" logger.info('BigchainDB Version %s', bigchaindb.__version__) - # TODO setup logging -- pass logging config, extracted out from main config - setup_logging() - if args.allow_temp_keypair: if not (bigchaindb.config['keypair']['private'] or bigchaindb.config['keypair']['public']): diff --git a/bigchaindb/commands/utils.py b/bigchaindb/commands/utils.py index b04499d9..73313f05 100644 --- a/bigchaindb/commands/utils.py +++ b/bigchaindb/commands/utils.py @@ -16,6 +16,7 @@ import bigchaindb import bigchaindb.config_utils from bigchaindb import backend from bigchaindb.common.exceptions import StartupError +from bigchaindb.log.setup import setup_logging from bigchaindb.version import __version__ @@ -23,6 +24,12 @@ def configure_bigchaindb(command): @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) + command(args) return configure @@ -151,6 +158,10 @@ base_parser.add_argument('-c', '--config', help='Specify the location of the configuration file ' '(use "-" for stdout)') +base_parser.add_argument('-l', '--log-level', + choices=['DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'], + help='Log level') + base_parser.add_argument('-y', '--yes', '--yes-please', action='store_true', help='Assume "yes" as answer to all prompts and run ' diff --git a/bigchaindb/config_utils.py b/bigchaindb/config_utils.py index 87a25d3f..5a72a7d6 100644 --- a/bigchaindb/config_utils.py +++ b/bigchaindb/config_utils.py @@ -220,11 +220,14 @@ def write_config(config, filename=None): json.dump(config, f, indent=4) +def is_configured(): + return bool(bigchaindb.config.get('CONFIGURED')) + + def autoconfigure(filename=None, config=None, force=False): """Run ``file_config`` and ``env_config`` if the module has not been initialized.""" - - if not force and bigchaindb.config.get('CONFIGURED'): + if not force and is_configured(): logger.debug('System already configured, skipping autoconfiguration') return diff --git a/tests/commands/conftest.py b/tests/commands/conftest.py index 96a2c608..30c577f5 100644 --- a/tests/commands/conftest.py +++ b/tests/commands/conftest.py @@ -55,7 +55,7 @@ def run_start_args(request): @pytest.fixture def mocked_setup_logging(mocker): return mocker.patch( - 'bigchaindb.commands.bigchain.setup_logging', + 'bigchaindb.commands.utils.setup_logging', autospec=True, spec_set=True, ) diff --git a/tests/commands/rethinkdb/test_commands.py b/tests/commands/rethinkdb/test_commands.py index bf6e0931..ac100075 100644 --- a/tests/commands/rethinkdb/test_commands.py +++ b/tests/commands/rethinkdb/test_commands.py @@ -16,7 +16,7 @@ def test_bigchain_run_start_with_rethinkdb(mock_start_rethinkdb, run_start(args) mock_start_rethinkdb.assert_called_with() - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) @patch('subprocess.Popen') @@ -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): +def test_set_shards(mock_reconfigure, monkeypatch, b, mocked_setup_logging): from bigchaindb.commands.bigchain import run_set_shards # this will mock the call to retrieve the database config @@ -50,6 +50,8 @@ def test_set_shards(mock_reconfigure, monkeypatch, b): 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 @@ -59,9 +61,10 @@ def test_set_shards(mock_reconfigure, monkeypatch, b): 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): +def test_set_shards_raises_exception(monkeypatch, b, mocked_setup_logging): from bigchaindb.commands.bigchain import run_set_shards # test that we are correctly catching the exception @@ -78,10 +81,11 @@ def test_set_shards_raises_exception(monkeypatch, b): 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): +def test_set_replicas(mock_reconfigure, monkeypatch, b, mocked_setup_logging): from bigchaindb.commands.bigchain import run_set_replicas # this will mock the call to retrieve the database config @@ -93,6 +97,8 @@ def test_set_replicas(mock_reconfigure, monkeypatch, b): 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 @@ -102,9 +108,10 @@ def test_set_replicas(mock_reconfigure, monkeypatch, b): 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): +def test_set_replicas_raises_exception(monkeypatch, b, mocked_setup_logging): from bigchaindb.commands.bigchain import run_set_replicas # test that we are correctly catching the exception @@ -121,3 +128,4 @@ def test_set_replicas_raises_exception(monkeypatch, b): 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 8bf00959..eebd86ea 100644 --- a/tests/commands/test_commands.py +++ b/tests/commands/test_commands.py @@ -40,7 +40,7 @@ def test_bigchain_run_start(mock_run_configure, from bigchaindb.commands.bigchain import run_start args = Namespace(start_rethinkdb=False, allow_temp_keypair=False, config=None, yes=True) run_start(args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) @pytest.mark.skipif(reason="BigchainDB doesn't support the automatic creation of a config file anymore") @@ -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): +def test_bigchain_show_config(capsys, mocked_setup_logging): from bigchaindb import config from bigchaindb.commands.bigchain import run_show_config @@ -85,9 +85,11 @@ def test_bigchain_show_config(capsys): 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): +def test_bigchain_export_my_pubkey_when_pubkey_set(capsys, monkeypatch, + mocked_setup_logging): from bigchaindb import config from bigchaindb.commands.bigchain import run_export_my_pubkey @@ -104,9 +106,11 @@ 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): +def test_bigchain_export_my_pubkey_when_pubkey_not_set(monkeypatch, + mocked_setup_logging): from bigchaindb import config from bigchaindb.commands.bigchain import run_export_my_pubkey @@ -122,41 +126,49 @@ 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(mock_db_init_with_existing_db): +def test_bigchain_run_init_when_db_exists(mocked_setup_logging, + 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): +def test_drop_db_when_assumed_yes(mock_db_drop, mocked_setup_logging): 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): +def test_drop_db_when_interactive_yes(mock_db_drop, monkeypatch, + mocked_setup_logging): 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): +def test_drop_db_does_not_drop_when_interactive_no(mock_db_drop, monkeypatch, + mocked_setup_logging): 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): @@ -245,7 +257,7 @@ def test_allow_temp_keypair_generates_one_on_the_fly( args = Namespace(allow_temp_keypair=True, start_rethinkdb=False, config=None, yes=True) run_start(args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) assert bigchaindb.config['keypair']['private'] == 'private_key' assert bigchaindb.config['keypair']['public'] == 'public_key' @@ -270,7 +282,7 @@ def test_allow_temp_keypair_doesnt_override_if_keypair_found(mock_gen_keypair, args = Namespace(allow_temp_keypair=True, start_rethinkdb=False, config=None, yes=True) run_start(args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) assert bigchaindb.config['keypair']['private'] == original_private_key assert bigchaindb.config['keypair']['public'] == original_public_key @@ -289,7 +301,7 @@ def test_run_start_when_db_already_exists(mocker, monkeypatch.setattr( 'bigchaindb.commands.bigchain._run_init', mock_run_init) run_start(run_start_args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) assert mocked_start.called @@ -311,7 +323,7 @@ def test_run_start_when_keypair_not_found(mocker, with pytest.raises(SystemExit) as exc: run_start(run_start_args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) assert len(exc.value.args) == 1 assert exc.value.args[0] == CANNOT_START_KEYPAIR_NOT_FOUND assert not mocked_start.called @@ -337,7 +349,7 @@ def test_run_start_when_start_rethinkdb_fails(mocker, with pytest.raises(SystemExit) as exc: run_start(run_start_args) - mocked_setup_logging.assert_called_once_with() + mocked_setup_logging.assert_called_once_with(user_log_config={}) assert len(exc.value.args) == 1 assert exc.value.args[0] == RETHINKDB_STARTUP_ERROR.format(err_msg) assert not mocked_start.called @@ -405,7 +417,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): +def test_run_add_replicas(mock_add_replicas, mocked_setup_logging): from bigchaindb.commands.bigchain import run_add_replicas from bigchaindb.backend.exceptions import OperationError @@ -415,7 +427,9 @@ def test_run_add_replicas(mock_add_replicas): 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') @@ -423,7 +437,9 @@ def test_run_add_replicas(mock_add_replicas): 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') @@ -431,12 +447,14 @@ def test_run_add_replicas(mock_add_replicas): 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): +def test_run_remove_replicas(mock_remove_replicas, mocked_setup_logging): from bigchaindb.commands.bigchain import run_remove_replicas from bigchaindb.backend.exceptions import OperationError @@ -446,6 +464,8 @@ def test_run_remove_replicas(mock_remove_replicas): 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` @@ -454,6 +474,8 @@ def test_run_remove_replicas(mock_remove_replicas): 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` @@ -462,4 +484,6 @@ def test_run_remove_replicas(mock_remove_replicas): 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 aadd24b5..223c1f99 100644 --- a/tests/commands/test_utils.py +++ b/tests/commands/test_utils.py @@ -1,9 +1,62 @@ import argparse +from argparse import ArgumentTypeError, Namespace +import logging +from logging import getLogger + import pytest from unittest.mock import patch +@pytest.fixture +def reset_bigchaindb_config(monkeypatch): + import bigchaindb + monkeypatch.setattr('bigchaindb.config', bigchaindb._config) + + +@pytest.mark.usefixtures('ignore_local_config_file', 'reset_bigchaindb_config') +def test_configure_bigchaindb_configures_bigchaindb(mocked_setup_logging): + from bigchaindb.commands.utils import configure_bigchaindb + from bigchaindb.config_utils import is_configured + assert not is_configured() + + @configure_bigchaindb + def test_configure(args): + assert is_configured() + + args = Namespace(config=None) + test_configure(args) + mocked_setup_logging.assert_called_once_with(user_log_config={}) + + +@pytest.mark.usefixtures('ignore_local_config_file', + 'reset_bigchaindb_config', + 'reset_logging_config') +@pytest.mark.parametrize('log_level', ( + logging.DEBUG, + logging.INFO, + logging.WARNING, + logging.ERROR, + logging.CRITICAL, +)) +def test_configure_bigchaindb_configures_logging(log_level, + mocked_setup_sub_logger): + from bigchaindb.commands.utils import configure_bigchaindb + from bigchaindb.log.configs import PUBLISHER_LOGGING_CONFIG + root_logger = getLogger() + assert root_logger.level == logging.NOTSET + + @configure_bigchaindb + def test_configure_logger(args): + root_logger = getLogger() + assert root_logger.level == PUBLISHER_LOGGING_CONFIG['root']['level'] + + 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}) + + def test_start_raises_if_command_not_implemented(): from bigchaindb.commands import utils from bigchaindb.commands.bigchain import create_parser @@ -51,13 +104,13 @@ def test_mongodb_host_type(): from bigchaindb.commands.utils import mongodb_host # bad port provided - with pytest.raises(argparse.ArgumentTypeError): + with pytest.raises(ArgumentTypeError): mongodb_host('localhost:11111111111') # no port information provided - with pytest.raises(argparse.ArgumentTypeError): + with pytest.raises(ArgumentTypeError): mongodb_host('localhost') # bad host provided - with pytest.raises(argparse.ArgumentTypeError): + with pytest.raises(ArgumentTypeError): mongodb_host(':27017') diff --git a/tests/conftest.py b/tests/conftest.py index e943d0a9..26beac11 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -12,6 +12,8 @@ import random import pytest +from logging import getLogger +from logging.config import dictConfig from bigchaindb.common import crypto TEST_DB_NAME = 'bigchain_test' @@ -203,6 +205,15 @@ def ignore_local_config_file(monkeypatch): mock_file_config) +@pytest.fixture +def reset_logging_config(): + # root_logger_level = getLogger().level + root_logger_level = 'DEBUG' + dictConfig({'version': 1, 'root': {'level': 'NOTSET'}}) + yield + getLogger().setLevel(root_logger_level) + + @pytest.fixture def user_sk(): return USER_PRIVATE_KEY @@ -431,3 +442,15 @@ def db_name(db_config): def db_conn(): from bigchaindb.backend import connect return connect() + + +@pytest.fixture +def mocked_setup_pub_logger(mocker): + return mocker.patch( + 'bigchaindb.log.setup.setup_pub_logger', autospec=True, spec_set=True) + + +@pytest.fixture +def mocked_setup_sub_logger(mocker): + return mocker.patch( + 'bigchaindb.log.setup.setup_sub_logger', autospec=True, spec_set=True) diff --git a/tests/log/test_setup.py b/tests/log/test_setup.py index e0434eb9..39a55995 100644 --- a/tests/log/test_setup.py +++ b/tests/log/test_setup.py @@ -30,18 +30,6 @@ def mocked_socket_server(mocker): ) -@fixture -def mocked_setup_pub_logger(mocker): - return mocker.patch( - 'bigchaindb.log.setup.setup_pub_logger', autospec=True, spec_set=True) - - -@fixture -def mocked_setup_sub_logger(mocker): - return mocker.patch( - 'bigchaindb.log.setup.setup_sub_logger', autospec=True, spec_set=True) - - @fixture def log_record_dict(): return { @@ -225,6 +213,7 @@ class TestLogRecordSocketServer: assert server.server_address == ( '127.0.0.1', logging.handlers.DEFAULT_TCP_LOGGING_PORT) assert server.RequestHandlerClass == LogRecordStreamHandler + server.server_close() @mark.parametrize('side_effect', (None, KeyboardInterrupt)) def test_server_forever(self, mocker, side_effect):