Skip to content

Migrations bug when creating stored procedure with GOTO statement #32457

@brandonryan

Description

@brandonryan

When upgrading from EFCore v6 to v8, some of our migrations started failing unexpectedly.
I have narrowed it down to the GOTO statements in the stored procedures that we create.
I think its an ef bug and not a SqlClient bug beacuse I can create the procedure using an SqlCommand();

Reproduceable example:
https://github.com/brandonryan/ReproEF8MigrationProc

In this reproduction I simply took the GOTO example directly from Sql Server documentation example and put it in a stored procedure.

Provider and version information

EF Core version: 8
Database provider: Microsoft.EntityFrameworkCore.SqlServer
Target framework: .NET 8.0
Operating system: Windows 11
IDE: Visual Studio Code
SQL Server: Microsoft SQL Server 2022 (RTM-GDR) (KB5029379) - 16.0.1105.1 (X64)

Application Logs / Stack Trace

warn: 11/29/2023 10:52:54.690 CoreEventId.SensitiveDataLoggingEnabledWarning[10400] (Microsoft.EntityFrameworkCore.Infrastructure) 
      Sensitive data logging is enabled. Log entries and exception messages may include sensitive application data; this mode should only be enabled during development.
dbug: 11/29/2023 10:52:54.722 CoreEventId.ContextInitialized[10403] (Microsoft.EntityFrameworkCore.Infrastructure) 
      Entity Framework Core 8.0.0 initialized 'AppContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer:8.0.0' with options: SensitiveDataLoggingEnabled
dbug: 11/29/2023 10:52:54.725 RelationalEventId.ConnectionCreating[20005] (Microsoft.EntityFrameworkCore.Database.Connection)
      Creating DbConnection.
dbug: 11/29/2023 10:52:54.743 RelationalEventId.ConnectionCreated[20006] (Microsoft.EntityFrameworkCore.Database.Connection) 
      Created DbConnection. (16ms).
dbug: 11/29/2023 10:52:54.744 RelationalEventId.MigrateUsingConnection[20400] (Microsoft.EntityFrameworkCore.Migrations)
      Migrating using database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.748 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.825 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection) 
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.828 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteNonQuery'.
dbug: 11/29/2023 10:52:54.830 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteNonQuery' (1ms).
dbug: 11/29/2023 10:52:54.831 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteNonQuery' (3ms).
dbug: 11/29/2023 10:52:54.834 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT 1
info: 11/29/2023 10:52:54.847 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed DbCommand (13ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT 1
dbug: 11/29/2023 10:52:54.849 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.852 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection) 
      Closed connection to database 'dbo' on server 'localhost' (2ms).
dbug: 11/29/2023 10:52:54.855 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteScalar'.
dbug: 11/29/2023 10:52:54.855 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteScalar' (0ms).
dbug: 11/29/2023 10:52:54.855 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteScalar' (0ms).
dbug: 11/29/2023 10:52:54.856 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.856 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.857 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT OBJECT_ID(N'[__EFMigrationsHistory]');
info: 11/29/2023 10:52:54.870 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) 
      Executed DbCommand (14ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT OBJECT_ID(N'[__EFMigrationsHistory]');
dbug: 11/29/2023 10:52:54.871 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.871 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closed connection to database 'dbo' on server 'localhost' (0ms).
dbug: 11/29/2023 10:52:54.872 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.872 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.872 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteNonQuery'.
dbug: 11/29/2023 10:52:54.873 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteNonQuery' (0ms).
dbug: 11/29/2023 10:52:54.873 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteNonQuery' (0ms).
dbug: 11/29/2023 10:52:54.873 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT 1
info: 11/29/2023 10:52:54.874 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (1ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT 1
dbug: 11/29/2023 10:52:54.875 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.875 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closed connection to database 'dbo' on server 'localhost' (0ms).
dbug: 11/29/2023 10:52:54.876 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteScalar'.
dbug: 11/29/2023 10:52:54.876 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteScalar' (0ms).
dbug: 11/29/2023 10:52:54.876 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteScalar' (0ms).
dbug: 11/29/2023 10:52:54.876 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.877 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.877 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT OBJECT_ID(N'[__EFMigrationsHistory]');
info: 11/29/2023 10:52:54.878 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (1ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT OBJECT_ID(N'[__EFMigrationsHistory]');
dbug: 11/29/2023 10:52:54.878 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.878 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closed connection to database 'dbo' on server 'localhost' (0ms).
dbug: 11/29/2023 10:52:54.945 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection) 
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.946 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.946 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteReader'.
dbug: 11/29/2023 10:52:54.946 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteReader' (0ms).
dbug: 11/29/2023 10:52:54.947 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteReader' (0ms).
dbug: 11/29/2023 10:52:54.947 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [MigrationId], [ProductVersion]
      FROM [__EFMigrationsHistory]
      ORDER BY [MigrationId];
info: 11/29/2023 10:52:54.951 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (4ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [MigrationId], [ProductVersion]
      FROM [__EFMigrationsHistory]
      ORDER BY [MigrationId];
dbug: 11/29/2023 10:52:54.954 RelationalEventId.DataReaderClosing[20301] (Microsoft.EntityFrameworkCore.Database.Command)
      Closing data reader to 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.955 RelationalEventId.DataReaderDisposing[20300] (Microsoft.EntityFrameworkCore.Database.Command)
      A data reader for 'dbo' on server 'localhost' is being disposed after spending 2ms reading results.
dbug: 11/29/2023 10:52:54.955 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.955 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closed connection to database 'dbo' on server 'localhost' (0ms).
info: 11/29/2023 10:52:54.960 RelationalEventId.MigrationApplying[20402] (Microsoft.EntityFrameworkCore.Migrations)
      Applying migration '20231129164838_Initial'.
dbug: 11/29/2023 10:52:54.966 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection) 
      Opening connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.966 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.968 RelationalEventId.TransactionStarting[20209] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Beginning transaction with isolation level 'Unspecified'.
dbug: 11/29/2023 10:52:54.970 RelationalEventId.TransactionStarted[20200] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Began transaction with isolation level 'ReadCommitted'.
dbug: 11/29/2023 10:52:54.971 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteNonQuery'.
dbug: 11/29/2023 10:52:54.971 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteNonQuery' (0ms).
dbug: 11/29/2023 10:52:54.972 RelationalEventId.CommandInitialized[20106] (Microsoft.EntityFrameworkCore.Database.Command)
      Initialized DbCommand for 'ExecuteNonQuery' (0ms).
dbug: 11/29/2023 10:52:54.972 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
          CREATE PROCEDURE [dbo].[GotoReproduction]
          AS
          BEGIN
              DECLARE @Counter int;
              SET @Counter = 1;
              WHILE @Counter < 10
              BEGIN
                  SELECT @Counter
                  SET @Counter = @Counter + 1
                  IF @Counter = 4 GOTO Branch_One --Jumps to the first branch.
                  IF @Counter = 5 GOTO Branch_Two --This will never execute.
              END
              Branch_One:
                  SELECT 'Jumping To Branch One.'
fail: 11/29/2023 10:52:54.974 RelationalEventId.CommandError[20102] (Microsoft.EntityFrameworkCore.Database.Command)
      Failed executing DbCommand (2ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
          CREATE PROCEDURE [dbo].[GotoReproduction]
          AS
          BEGIN
              DECLARE @Counter int;
              SET @Counter = 1;
              WHILE @Counter < 10
              BEGIN
                  SELECT @Counter
                  SET @Counter = @Counter + 1
                  IF @Counter = 4 GOTO Branch_One --Jumps to the first branch.
                  IF @Counter = 5 GOTO Branch_Two --This will never execute.
              END
              Branch_One:
                  SELECT 'Jumping To Branch One.'
dbug: 11/29/2023 10:52:54.976 RelationalEventId.TransactionDisposed[20204] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Disposing transaction.
dbug: 11/29/2023 10:52:54.977 RelationalEventId.ConnectionClosing[20002] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closing connection to database 'dbo' on server 'localhost'.
dbug: 11/29/2023 10:52:54.977 RelationalEventId.ConnectionClosed[20003] (Microsoft.EntityFrameworkCore.Database.Connection)
      Closed connection to database 'dbo' on server 'localhost' (0ms).
Unhandled exception. Microsoft.Data.SqlClient.SqlException (0x80131904): Incorrect syntax near 'Jumping To Branch One.'.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at Microsoft.Data.SqlClient.SqlCommand.InternalEndExecuteNonQuery(IAsyncResult asyncResult, Boolean isInternal, String endMethod)
   at Microsoft.Data.SqlClient.SqlCommand.EndExecuteNonQueryInternal(IAsyncResult asyncResult)
   at Microsoft.Data.SqlClient.SqlCommand.EndExecuteNonQueryAsync(IAsyncResult asyncResult)
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<InternalExecuteNonQueryAsync>b__208_1(IAsyncResult result)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location ---
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQueryAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQueryAsync(IEnumerable`1 migrationCommands, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQueryAsync(IEnumerable`1 migrationCommands, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQueryAsync(IEnumerable`1 migrationCommands, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQueryAsync(IEnumerable`1 migrationCommands, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.Migrator.MigrateAsync(String targetMigration, CancellationToken cancellationToken)
   at ReproEF8MigrationProc.Program.Main() in C:\Users\bryan\Development\ReproEF8MigrationProc\Program.cs:line 12
   at ReproEF8MigrationProc.Program.<Main>()
ClientConnectionId:b43bc3b5-0fc2-4d8f-9225-0958e0c80d8d
Error Number:102,State:1,Class:15

Metadata

Metadata

Assignees

No one assigned

    Type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions