def test_stats_logging_with_error(logger):
study = StudyDefinition(
population=patients.all(),
event=patients.with_these_clinical_events(codelist(["A"], "snomed")),
)
# insert a deliberate error in the queries
study.backend.queries[-1] = "SELECT Foo FROM Bar"
with pytest.raises(Exception) as excinfo:
study.to_dicts()
# The error is raised as expected
assert "Invalid object name 'Bar'" in str(excinfo.value)
# Timing is logged, with the error state in the end log
(sql_log, ) = [
log for log in logger.entries
if log.get("sql") == "SELECT Foo FROM Bar"
]
(end_log, ) = [
log for log in logger.entries
if log.get("timing_id") == sql_log["timing_id"]
and log.get("timing") == "stop"
]
assert end_log["state"] == "error"
def test_stats_logging_with_message_handle_exception(mock_regex, logger):
mock_regex.match.side_effect = Exception("message error")
study = StudyDefinition(
population=patients.all(),
event=patients.with_these_clinical_events(codelist(["A"], "snomed")),
)
study.to_dicts()
cohortextractor_stats_logs = get_stats_logs(logger.entries)
timing_logs = get_logs_by_key(cohortextractor_stats_logs, "timing_id")
sqlserver_stats_logs = get_stats_logs(logger.entries,
event="sqlserver-stats")
# Study runs OK and we still get the normal cohortextractor-stats timing logs
assert len(timing_logs) > 0
# sqlserver-stats logs just consist of the error logs
for log in sqlserver_stats_logs:
assert log["description"] == "Exception in SQL server message handling"
assert str(log["exc_info"]) == "message error"
def test_stats_logging_tpp_backend(logger):
# The query counter is a global at the module level, so it isn't reset between tests
# Find the next position (without incrementing it); this is the start of the test's timing logs
start_counter = timing_log_counter.next
study = StudyDefinition(
population=patients.all(),
event=patients.with_these_clinical_events(codelist(["A"], "snomed")),
)
study.to_dicts()
# initial stats
expected_initial_study_def_logs = [
# output columns include patient_id, and the 2 variables defined in the
# study defniiton
# tables - Patient, temp event table for codelist
{
"output_column_count": 3,
"table_count": 2,
"table_joins_count": 1
},
{
"variable_count": 2
},
{
"variables_using_codelist_count": 1
},
{
"variable_using_codelist": "event",
"codelist_size": 1
},
]
# timing stats
# logs in tpp_backend during query execution
expected_timing_log_params = [
*_sql_execute_timing_logs(
description="Uploading codelist for event",
sql="CREATE TABLE #tmp1_event_codelist",
timing_id=start_counter,
),
*_sql_execute_timing_logs(
description=None,
sql=
"INSERT INTO #tmp1_event_codelist (code, category) VALUES\n[truncated]",
timing_id=start_counter + 1,
is_truncated=True,
),
*_sql_execute_timing_logs(
description="Query for event",
sql="SELECT * INTO #event",
timing_id=start_counter + 2,
),
*_sql_execute_timing_logs(
description="Query for population",
sql="SELECT * INTO #population",
timing_id=start_counter + 3,
),
*_sql_execute_timing_logs(
description="Join all columns for final output",
sql="JOIN #event ON #event.patient_id = #population.patient_id",
timing_id=start_counter + 4,
),
]
assert_stats_logs(
logger,
expected_initial_study_def_logs,
expected_timing_log_params,
downloaded=False,
)
