Show Actual Query Plan causes error?

Question

Curious if anyone has experienced this problem before and what the root cause is. The problem is that an error occurs when executed in SQL 2012 with Include Actual Query Plan turned on. It works in 2008 R2 either way (with or without plan) and works in 2012 without the Plan turned on. I discovered this when testing out functionality against partitioned views.

--Setup
USE master
go 

DROP DATABASE Test
GO

CREATE DATABASE Test
GO

USE Test
GO

CREATE TABLE DD (pkID int IDENTITY(1,1), FullDate date);
INSERT INTO DD (FullDate) VALUES ('2013-01-01')
INSERT INTO DD (FullDate) VALUES ('2013-01-02')
INSERT INTO DD (FullDate) VALUES ('2013-01-03')
INSERT INTO DD (FullDate) VALUES ('2013-01-04')
INSERT INTO DD (FullDate) VALUES ('2013-01-05')
GO

CREATE TABLE DC (pkID int IDENTITY(1,1), Filter varchar(32), FilterGroup varchar(32));
INSERT INTO DC (Filter, FilterGroup) VALUES ('one', 'groupone')
INSERT INTO DC (Filter, FilterGroup) VALUES ('two', 'grouptwo')
INSERT INTO DC (Filter, FilterGroup) VALUES ('three', 'groupone')
GO

CREATE TABLE FDA1 (pkID int IDENTITY(1,1), fkpID int, fkCID int, fkDateID int)
INSERT INTO FDA1(fkpID, fkCID, fkDateID) VALUES (1,1,1)
INSERT INTO FDA1(fkpID, fkCID, fkDateID) VALUES (1,2,1)
INSERT INTO FDA1(fkpID, fkCID, fkDateID) VALUES (1,1,3)
INSERT INTO FDA1(fkpID, fkCID, fkDateID) VALUES (1,3,5)
GO

CREATE TABLE FDA2 (pkID int IDENTITY(1,1), fkpID int, fkCID int, fkDateID int)
INSERT INTO FDA2(fkpID, fkCID, fkDateID) VALUES (2,1,2)
INSERT INTO FDA2(fkpID, fkCID, fkDateID) VALUES (2,2,2)
INSERT INTO FDA2(fkpID, fkCID, fkDateID) VALUES (2,1,4)
INSERT INTO FDA2(fkpID, fkCID, fkDateID) VALUES (2,3,5)
GO

CREATE VIEW FDA 
AS
    SELECT pkID, fkpID, fkCID, fkDateID FROM FDA1
    UNION ALL
    SELECT pkID, fkpID, fkCID, fkDateID FROM FDA2
GO

CREATE FUNCTION GetFilter
(
    @pID int
    , @filterGroup varchar(32)
)
RETURNS @Filter TABLE 
(
    CID int
)
AS
BEGIN
    INSERT INTO
        @Filter
    SELECT 
        dc.pkID 
    FROM
        DC dc
    WHERE
        dc.FilterGroup = @filterGroup 
    RETURN
END
GO

CREATE PROC test (@ID int)
AS
BEGIN
    BEGIN TRY
        DECLARE @FilterGroup varchar(32) = 'groupone'

        SELECT
            CAST(MIN(dd.FullDate) As datetime) as ProjectReviewStartDate
        FROM
            dbo.FDA fda
            INNER JOIN dbo.DD dd On fda.fkDateID = dd.pkID 
            INNER JOIN dbo.GetFilter(@ID, @FilterGroup) ctl on fda.fkCID = ctl.CID  
        WHERE
            fda.pkID = @ID 
        OPTION (RECOMPILE);
        RETURN 0;
    END TRY
    BEGIN CATCH

        --Declare variables for error information.
        Declare
            @ErrorMessage nvarchar(max),
            @ErrorSeverity bigint,
            @ErrorState int;

        --Populate error information.
        Select
            @ErrorMessage = ERROR_MESSAGE(),
            @ErrorSeverity = ERROR_SEVERITY(),
            @ErrorState = ERROR_STATE();

        --Re-throw error to calling method.
        RAISERROR(@ErrorMessage, @ErrorSeverity, @ErrorState);

        --Failure
        RETURN -1;
    END CATCH;
END
GO

Now that setup is done, let's run the actual code, first "Include Actual Execution Plan"

USE Test
GO

SET STATISTICS IO ON;
SET STATISTICS TIME ON;
GO

DECLARE @id int = 1
DECLARE @tbl table (dt datetime)
DECLARE @findate datetime

INSERT @tbl EXEC test @id

SELECT @findate = dt FROM @tbl
SELECT @findate
GO

You should receive the result of: 2013-01-01 00:00:00.000.

Now turn on Include Actual Execution Plan and you will receive the result of NULL and see an error (In SQL 2012):

Msg 50000, Level 16, State 10, Procedure test, Line 33 String or binary data would be truncated.

With Include Actual Execution Plan on and removing the Try/Catch block from the proc removes the error and returns the correct result. However again this works fine in 2008R2.

Any ideas?

Thanks

Answer 1

I don't have an answer for you yet, just more ammo that you have likely encountered a bug.

First, to prove that this doesn't involve RAISERROR specifically, changing that line to:

THROW;

Returns this error message instead:

Msg 8152, Level 16, State 10, Procedure test, Line 7
String or binary data would be truncated.

So this shows that the error is happening in the SELECT call and has something to do with the combination of TRY/CATCH and show actual plan.

Next, let's see what the metadata describes as the output for the stored procedure:

SELECT name, system_type_name
  FROM sys.dm_exec_describe_first_result_set_for_object
  (OBJECT_ID('test'), NULL);

Results:

name                    system_type_name
----------------------  ----------------
ProjectReviewStartDate  datetime

Now let's see what it says about the metadata (well, actually, turns out an error message) if we try to test the metadata for the batch you're running:

SELECT [error_message]
FROM sys.dm_exec_describe_first_result_set(N'DECLARE @id int = 1
  DECLARE @tbl table (dt datetime)
 DECLARE @findate datetime
 INSERT @tbl 
 EXEC test @id', -1, NULL);

The result:

error_message
----------------------------------------------------------
Incorrect syntax near '-'.
The batch could not be analyzed because of compile errors.

There is no - in the batch. And this is with execution plan turned off. And you get the same result even if you comment out the insert in the batch above. Even for example:

SELECT error_message
  FROM sys.dm_exec_describe_first_result_set(N'EXEC test 1', -1, NULL);

The error message changes ever so slightly (look closely):

error_message
----------------------------------------------------------
Incorrect syntax near '1'.
The batch could not be analyzed because of compile errors.

We've removed any involvement of showplan or potential truncation and we still can demonstrate that SQL Server has some kind of problem compiling and/or generating metadata for this simple batch.

Seems to be a pretty simple repro, and you have workarounds, and the bug you filed appears to have been fixed.

---

But I came across another scenario recently that I probably just forgot was the case: when you turn on Include Actual Execution Plan, sys.dm_exec_describe_result_set doesn't work as expected. I had already created a view that did something like this:

CREATE VIEW dbo.MyView 
AS
  SELECT [Table]  = t.name, 
         [Column] = y.name, 
         [Type]   = y.system_type_name
  FROM sys.tables AS t
  CROSS APPLY sys.dm_exec_describe_first_result_set
  (N'SELECT * FROM dbo.' + t.name, NULL, 0) AS y;

Calling the view worked fine - it returned 5 rows from Orders, 12 rows from OrderDetails, and so on.

However, when I queried the view in a batch that also had execution plan turned on, it returned one row from each table, with NULL for Column and Type. To see what was happening, I just added y.* to the view, and then I remembered:

error_message
-------------
sp_describe_first_result_set cannot be invoked when SET STATISTICS XML or SET STATISTICS PROFILE is on.

Which isn't going to be as obvious to consumers of the view who happen to turn on execution plan. So I changed the view to say:

[Column] = CONCAT(y.name, y.error_message),

And if I wanted it to be even friendlier:

[Column] = CONCAT(y.name, 
  CASE WHEN y.error_message LIKE N'%SET STATISTICS%'
  THEN N'Output is limited because execution plan is on.'
  ELSE y.error_message END),