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, )