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"