Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

SqlPackage Import fails with timeout when enabling triggers #93

Open
craigminihan opened this issue Apr 21, 2022 · 5 comments
Open

SqlPackage Import fails with timeout when enabling triggers #93

craigminihan opened this issue Apr 21, 2022 · 5 comments
Labels
bug Something isn't working

Comments

@craigminihan
Copy link

  • SqlPackage or DacFx Version: 16.0.5400.1
  • .NET Framework (Windows-only) or .NET Core: 4.7.02053
  • Environment (local platform and source/target platforms): Windows Server 2019 Standard, SQL Server 2017, Azure SQL Database

Steps to Reproduce:

  1. Export database with SqlPackage to bacpac file
  2. Import database with SqlPackage into Azure SQL Database Elastic Pool (Gen5 8 vCores)
  3. Import runs and completes processing tables and enables indexes
  4. Timeout when enabling triggers as follows:
Microsoft.Data.Tools.Diagnostics.Tracer Verbose: 0 : 2022-04-21T21:01:42 : Executing Step 1492, Not Tracked, Type 'EnableDmlTriggersStep', Section 'None', Operation '0', Ignorable Errors 'None', Script is as follows: 

ENABLE TRIGGER [dbo].[trig_Search_Specification]
    ON [dbo].[tbl_Company_Specification];

Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-04-21T21:02:12 : Retry requested: Retry count = 1. Delay = 00:00:00.2500000, SQL Error Code = -2146232060, SQL Error Number = -2, Can retry error = True, Will retry = True Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<RunExecuteReaderTds>b__243_0()
   at Microsoft.Data.SqlClient.AsyncHelper.WaitForCompletion(Task task, Int32 timeout, Action onTimeout, Boolean rethrowExceptions)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.QuerySessionSettings(IDbCommand originalCommand)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.CacheOrReplaySessionSettings(IDbCommand originalCommand, Tuple`2[] sessionSettings)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.<>c__DisplayClass2.<ExecuteReader>b__1()
   at Microsoft.Data.Tools.Schema.Common.SqlClient.RetryPolicy.ExecuteAction[R](Func`2 func, Nullable`1 token)
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:-2,State:0,Class:11
Microsoft.Data.Tools.Diagnostics.Tracer Warning: 0 : 2022-04-21T21:02:12 : Retry occurred: session: 77dffe89-d0f0-4047-8f47-27c9e1095d13; attempt - 1; delay - 00:00:00.2500000; exception - "Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<RunExecuteReaderTds>b__243_0()
   at Microsoft.Data.SqlClient.AsyncHelper.WaitForCompletion(Task task, Int32 timeout, Action onTimeout, Boolean rethrowExceptions)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.QuerySessionSettings(IDbCommand originalCommand)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.CacheOrReplaySessionSettings(IDbCommand originalCommand, Tuple`2[] sessionSettings)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.<>c__DisplayClass2.<ExecuteReader>b__1()
   at Microsoft.Data.Tools.Schema.Common.SqlClient.RetryPolicy.ExecuteAction[R](Func`2 func, Nullable`1 token)
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:-2,State:0,Class:11"
Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-04-21T21:02:12 : Retry requested: Retry count = 1. Delay = 00:00:00.2500000, SQL Error Code = -2146232060, SQL Error Number = -2, Can retry error = True, Will retry = True Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<RunExecuteReaderTds>b__243_0()
   at Microsoft.Data.SqlClient.AsyncHelper.WaitForCompletion(Task task, Int32 timeout, Action onTimeout, Boolean rethrowExceptions)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.QuerySessionSettings(IDbCommand originalCommand)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.CacheOrReplaySessionSettings(IDbCommand originalCommand, Tuple`2[] sessionSettings)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.<>c__DisplayClass5.<ExecuteScalar>b__4()
   at Microsoft.Data.Tools.Schema.Common.SqlClient.RetryPolicy.ExecuteAction[R](Func`2 func, Nullable`1 token)
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:-2,State:0,Class:11
Microsoft.Data.Tools.Diagnostics.Tracer Warning: 0 : 2022-04-21T21:02:12 : Retry occurred: session: 77dffe89-d0f0-4047-8f47-27c9e1095d13; attempt - 1; delay - 00:00:00.2500000; exception - "Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
   at Microsoft.Data.SqlClient.SqlCommand.<>c.<RunExecuteReaderTds>b__243_0()
   at Microsoft.Data.SqlClient.AsyncHelper.WaitForCompletion(Task task, Int32 timeout, Action onTimeout, Boolean rethrowExceptions)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.QuerySessionSettings(IDbCommand originalCommand)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.CacheOrReplaySessionSettings(IDbCommand originalCommand, Tuple`2[] sessionSettings)
   at Microsoft.Data.Tools.Schema.Common.SqlClient.ReliableSqlConnection.<>c__DisplayClass5.<ExecuteScalar>b__4()
   at Microsoft.Data.Tools.Schema.Common.SqlClient.RetryPolicy.ExecuteAction[R](Func`2 func, Nullable`1 token)
ClientConnectionId:00000000-0000-0000-0000-000000000000
Error Number:-2,State:0,Class:11"

etc.

Post failure the trigger can be enabled in SSMS with no issue via the context menu or executing the ENABLE TRIGGER directly.

Intervening during the retry sequence and enabling the trigger does not affect the outcome, the retry loop continues with eventual failure of the import.

Did this occur in prior versions? If not - which version(s) did it work in?
Unknown

(DacFx/SqlPackage/SSMS/Azure Data Studio)
@craigminihan craigminihan added the bug Something isn't working label Apr 21, 2022
@kisantia
Copy link
Contributor

DacFx does not support importing into elastic pools, as mentioned in the limitations for bacpacs. The workaround for importing into an elastic pool is to create a single database for DacFx operations, then move the database into an elastic pool. Can you try doing this and see if the enabling triggers is still timing out?

There are also a couple parameters that might help with the timeout error: /p:CommandTimeout and /p: LongRunningCommandTimeout. More info on these options can be found here.

@craigminihan
Copy link
Author

@kisantia thanks for the pointers, I'll run it into a dedicated Gen5 now.

Timeout-wise I'm already using:

  • /TargetTimeout:60
  • /p:CommandTimeout=3600
  • /p:LongRunningCommandTimeout=0

Let me know if you recommend other timeout values.

@craigminihan
Copy link
Author

@kisantia I ran on a Gen5 Business Critical 8 vCore, however it failed on the triggers in exactly the same way as before.

I created a new backup with a /TableData:smalltable param to restrict the amount of data in the bacpac. I ran the import against this new file and it completed correctly. The full file is 16GB in size, the small version is 0.5MB.

@kisantia
Copy link
Contributor

kisantia commented May 3, 2022

@craigminihan can you try increasing the TargetTimeout and /p:CommandTimeout?

@craigminihan
Copy link
Author

@kisantia I updated the timeouts to /TargetTimeout:600 and /p:CommandTimeout=7200 but the end result was the same.

Reviewing the logs I can see the following timestamps:

  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-05-04T00:43:59 : Retry requested: Retry count = 1
  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-05-04T00:44:29 : Ignore Error requested: Retry count = 1
  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-05-04T00:45:00 : Ignore Error requested: Retry count = 2
  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-05-04T00:45:30 : Ignore Error requested: Retry count = 3
  • ...
  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 19 : 2022-05-04T01:02:04 : Retry requested: Retry count = 24
  • Microsoft.Data.Tools.Diagnostics.Tracer Error: 0 : 2022-05-04T01:02:04 : Unable to retrieve Azure session-id

The retry sequence suggests a 30s timeout is being used. During this time CPU and IO counts on the database are both zero suggesting there is nothing actually happening.

The trigger which appears to cause the timeout is not enabled by the import. Later when enabled in SSMS it completes instantly.

@tomaustin700 tomaustin700 mentioned this issue Dec 20, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@craigminihan @kisantia