def test_cli_logger(monkeypatch): # noqa: F811
logger = _get_cli_logger(monkeypatch)
logger.info("test_cli_logger",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| INFO | hopeit.engine {version.ENGINE_VERSION} test_cli_logger test_host test_pid " \
"| [test_cli_logger] Log message | extra.field1=value1 | extra.field2=42"
logger.warning("test_cli_logger",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| WARNING | hopeit.engine {version.ENGINE_VERSION} test_cli_logger test_host test_pid " \
"| [test_cli_logger] Log message | extra.field1=value1 | extra.field2=42"
logger.error("test_cli_logger",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| ERROR | hopeit.engine {version.ENGINE_VERSION} test_cli_logger test_host test_pid " \
"| [test_cli_logger] Log message | extra.field1=value1 | extra.field2=42"
def test_engine_logger_no_context(monkeypatch, mock_app_config): # noqa: F811
logger = _get_engine_logger(monkeypatch, mock_app_config)
logger.info("test_it_logging",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| INFO | {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Log message " \
"| extra.field1=value1 | extra.field2=42"
logger.warning("test_it_logging",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| WARNING " \
f"| {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Log message " \
"| extra.field1=value1 | extra.field2=42"
logger.error("test_it_logging",
"Log message",
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| ERROR | {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Log message " \
"| extra.field1=value1 | extra.field2=42"
def test_engine_logger_traceback(monkeypatch, mock_app_config): # noqa: F811
logger = _get_engine_logger(monkeypatch, mock_app_config)
exc = AssertionError("Test for error")
logger.info("test_it_logging",
exc,
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| INFO | {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Test for error " \
"| extra.field1=value1 | extra.field2=42 " \
"| trace=%5B%22AssertionError%3A%20Test%20for%20error%5Cn%22%5D"
logger.warning("test_it_logging",
exc,
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| WARNING " \
f"| {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Test for error " \
"| extra.field1=value1 | extra.field2=42 " \
"| trace=%5B%22AssertionError%3A%20Test%20for%20error%5Cn%22%5D"
logger.error("test_it_logging",
exc,
extra=server_logging.extra_values([],
field1='value1',
field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== f"| ERROR | {version.ENGINE_NAME} {version.ENGINE_VERSION} engine test_host test_pid " \
"| [test_it_logging] Test for error " \
"| extra.field1=value1 | extra.field2=42 " \
"| trace=%5B%22AssertionError%3A%20Test%20for%20error%5Cn%22%5D"
def test_engine_extra_logger(monkeypatch, mock_app_config): # noqa: F811
logger, extra = _get_engine_extra_logger(monkeypatch, mock_app_config)
context = _event_context(mock_app_config)
logger.info(context,
"Log message",
extra=extra(field1='value1', field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| INFO | mock_app test mock_event_logging test_host test_pid | Log message " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.warning(context,
"Log message",
extra=extra(field1='value1', field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| WARNING | mock_app test mock_event_logging test_host test_pid | Log message " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.error(context,
"Log message",
extra=extra(field1='value1', field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| ERROR | mock_app test mock_event_logging test_host test_pid | Log message " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.debug(context,
"Log message",
extra=extra(field1='value1', field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| DEBUG | mock_app test mock_event_logging test_host test_pid | Log message " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.start(context, extra=extra(field1='value1', field2=42))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| INFO | mock_app test mock_event_logging test_host test_pid | START " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.done(context,
extra=server_logging.combined(extra(field1='value1',
field2=42)))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| INFO | mock_app test mock_event_logging test_host test_pid | DONE " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.ignored(context,
extra=server_logging.combined(
extra(field1='value1', field2=42)))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| WARNING | mock_app test mock_event_logging test_host test_pid | IGNORED " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"
logger.failed(context,
extra=server_logging.combined(
server_logging.extra_values([],
field1='value1',
field2=42)))
assert MockHandler.formatter.format(MockHandler.record)[24:] \
== "| ERROR | mock_app test mock_event_logging test_host test_pid | FAILED " \
"| extra.field1=value1 | extra.field2=42 " \
"| track.operation_id=test_operation_id " \
"| track.request_id=test_request_id | track.request_ts=2020-01-01T00:00:00Z " \
"| track.session_id=test_session_id | event.app=mock_app.test"