How can I measure the impact of queries with errors being rejected by SQL Server?

Question

After configuring XE on November 23, 2020 to capture some errors I could count 2,163,665 occurrences of the same error coming from requests of a legacy app (that probably won’t be corrected so soon). The errors can be classified on the 1st and 2nd steps for Processing a SQL Statement:

1. The DBMS first parses the SQL statement. It breaks the statement up into individual words, called tokens, makes sure that the statement has a valid verb and valid clauses, and so on. Syntax errors and misspellings can be detected in this step.
2. The DBMS validates the statement. It checks the statement against the system catalog. Do all the tables named in the statement exist in the database? Do all of the columns exist and are the column names unambiguous? Does the user have the required privileges to execute the statement? Certain semantic errors can be detected in this step.

The doc also says that Parsing a SQL statement does not require access to the database and can be done very quickly, but the amount of requests being fired at the server made me think I should verify.

I’d like to measure the resource consumption impact caused by those wrong requests being rejected on those steps. Is there a way to do so?

Answer 1

I see from your comment that the errors are not happening so frequently as to be a performance concern.

To answer the question asked, you could create a filtered XE trace to capture detail sql_batch_completed and rpc_completed events where result is Error. The events can then be summarized by a time interval for aggregated stats.

The example below summarizes the CPU and logical reads by one minute interval from a trace file target.

--example trace
CREATE EVENT SESSION [errors] ON SERVER 
ADD EVENT sqlserver.rpc_completed(SET collect_statement=(1)
    WHERE ([result]=(1))),
ADD EVENT sqlserver.sql_batch_completed(
    WHERE ([result]=(1)))
ADD TARGET package0.event_file(SET filename=N'C:\TraceFiles\errors',max_rollover_files=(2))
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF);
GO

--example aggregation query
WITH
    event_data AS (
        SELECT CAST(event_data AS XML) AS event_data_xml
        FROM fn_xe_file_target_read_file('C:\TraceFiles\errors*.xel',NULL,NULL,NULL)
    )
    , event_data_fields AS (
        SELECT 
              DATEADD(minute,DATEDIFF(minute,'',event_data_xml.value('(/event/@timestamp)[1]', 'datetime2')),'') AS interval
            , event_data_xml.value('(/event/data[@name="duration"]/value)[1]', 'bigint') AS duration
            , event_data_xml.value('(/event/data[@name="cpu_time"]/value)[1]', 'bigint') AS cpu_time
            , event_data_xml.value('(/event/data[@name="logical_reads"]/value)[1]', 'bigint') AS logical_reads
        FROM event_data
    )
SELECT
      interval
    , SUM(duration) AS duration
    , SUM(cpu_time) AS cpu_time
    , SUM(logical_reads) AS logical_reads
FROM event_data_fields
GROUP BY interval
ORDER BY interval;