Lesson Learned #237: Long running operation failed with status 'NotFound' creating a database

[Guest Jose_Manuel_Jurado]

Several days ago, I worked on a service request that our customer is using Microsoft.Azure.Management.Sql ( NuGet Microsoft.Azure.Management.Sql 3.0.0-preview) component that automatize, using REST-API, operations like creation of Azure SQL Servers and Azure SQL Database, etc..

 

 

 

In some situations, we could receive this type of error message {"Long running operation failed with status 'NotFound'."} and I would like to share with you how to mitigate it and best practices.

 

 

 

First of all, we need to know that all operations are asyncronous and even when we received the confirmation of the creation of the resource we might wait a couple of minutes to have all elements created correctly. You could find more information in this URL

 

using TSQL and PowerShell.

 

 

 

In this case, I'm going to use this Microsoft.Azure.Management.Sql component to perform the operations of server and database, creation and deletion. In other to test this POC, I'm going to run the following process running the following tasks:

 

 

 

• All operation calls are syncronous but, you might have the same problem using async calls.
  
• I'm going to run 10 times deleting and creationg a database
  
• 
  The parameter bCheck will use, in every call of the function bCreateDatabase and bDeleteDatabase to check two things:
   
  
  • 
    For every creation:
     
    
    • 
      Check if the server already exists
       
       
      
    • 
      Check if the database already exists.
       
       
      
    • 
      If both exists, try to create the database:
       
      
      • 
        In case of success
         
        
        • 
          Check if the database_operation_status reported value 2, if not, wait 5 seconds for giving time the workflow to complete the process.
           
           
          
        • 
          Check if after creating the database the status is 0 using sys.databases, if not, wait 5 seconds for giving time the workflow to complete the process.
           
           
          
        • Check if after deleting the database this doesn't exist using sys.databases. if not, wait 5 seconds for giving time the workflow to complete the process.
          
        • Finally, give another 5 seconds to complete the workflow process (https://management.core.windows.net/) finished.
          

        [*]In case of failure,

        • 
          Retry the operation 3 times at least
           
          

 

 

 

In my POC, assigning the value True to this parameter, all operations were executed succesfully.

 

 

 

 

 

#region "Azure Operations"

int i;

int iRetries = 0;

ClsOpsDBUsingMicrosoftAzureManagementSql oClsOps = new ClsOpsDBUsingMicrosoftAzureManagementSql();

ClsWriteLog oClsWriteLog = new ClsWriteLog();

if (oClsOps.bCreateServer(ref sMsg, "servername", "Default-SQL-NorthEurope"))

{

Console.WriteLine("bCreateServer - Executed Operation # {0} - {1}", i,sMsg);

}

 

String sMsg = "";

Boolean bCheck = true;

for (i=1;i<=10; i++)

{

sMsg = "";

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " is executing.", ConsoleColor.Blue);

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executing the bCreateDatabase process.", ConsoleColor.Blue);

Boolean bOperation = false;

while (!bOperation)

{

iRetries++;

bOperation = oClsOps.bCreateDatabase(ref sMsg, "servername", "Default-SQL-NorthEurope", "databasename", bCheck);

System.Threading.Thread.Sleep(5000);

if(iRetries > 3)

{

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executed with error process.", ConsoleColor.Blue);

}

}

 

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executed the bCreateDatabase process.", ConsoleColor.Blue);

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executing the bDeleteDatabase process.", ConsoleColor.Blue);

 

bOperation = false;

iRetries = 0;

while (!bOperation)

{

iRetries++;

bOperation = oClsOps.bDeleteDatabase(ref sMsg, "servername", "Default-SQL-NorthEurope", "databasename", bCheck);

System.Threading.Thread.Sleep(5000);

if (iRetries > 3)

{

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executed with error process.", ConsoleColor.Blue);

}

}

oClsWriteLog.WriteSomethingInConsole("Operation " + i.ToString() + " executed the bDeleteDatabase process.", ConsoleColor.Blue);

}

#endregion

 

 

 

 

 

Following you could find the C# code with all operations implemented:

 

 

 

 

 

using System;

using System.Collections.Generic;

using System.Linq;

using System.Text;

using System.Threading.Tasks;

using Microsoft.Azure;

using Microsoft.Azure.Management.Sql;

using Microsoft.IdentityModel.Clients.ActiveDirectory;

using System.Security.Cryptography.X509Certificates;

using C = System.Data.SqlClient;

using System.Data;

 

namespace DotNetExample

{

class ClsOpsDBUsingMicrosoftAzureManagementSql

{

public Boolean bCreateServer(ref String sMsg, string sServerName = "", string sRGName = "")

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

try

{

SqlManagementClient SqlClient = GetAccessClient("bCreateServer");

Boolean bReturn = false;

if (!bCheckIfServerExist(ref sMsg, sServerName))

{

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateServer - Server doesn't exist " + sServerName.ToString() + " in resource group:" + sRGName.ToString() + " creating it...", ConsoleColor.Green);

SqlClient.Servers.CreateOrUpdate(sRGName, sServerName, new Microsoft.Azure.Management.Sql.Models.Server

{

AdministratorLogin = "adminuser",

AdministratorLoginPassword = "Password",

Location = "WestEurope"

});

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateServer - Server created " + sServerName.ToString() + " in resource grop:" + sRGName.ToString(), ConsoleColor.Green);

bReturn = true;

}

return bReturn;

}

catch (Exception e)

{

sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateServer - Error Creating Server " + sServerName.ToString() + " in resource group:" + sRGName.ToString() + " Error:" + sMsg.ToString(), ConsoleColor.Red);

return false;

}

}

 

public Boolean bCreateDatabase(ref String sMsg, string sServerName = "", string sRGName = "", string sDBName = "", Boolean bCheck = true)

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

try

{

SqlManagementClient SqlClient = GetAccessClient("bCreateDatabase");

Boolean bReturn = false;

Microsoft.Azure.Management.Sql.Models.Sku Skus = new Microsoft.Azure.Management.Sql.Models.Sku("S0", "Standard");

 

if (bCheckIfServerExist(ref sMsg, sServerName, bCheck))

{

if (!bCheckIfDatabaseExist(ref sMsg, sServerName, sRGName, sDBName,bCheck, false))

{

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateDatabase - Creating the database " + sDBName.ToString() + " in server: " + sServerName.ToString(), ConsoleColor.Magenta);

SqlClient.Databases.CreateOrUpdate(sRGName, sServerName, sDBName, new Microsoft.Azure.Management.Sql.Models.Database

{

Collation = "SQL_Latin1_General_CP1_CI_AS",

Sku = Skus,

Location = "WestEurope"

});

if (bCheck)

{

while (!bOperationFinished(ref sMsg, sServerName, sDBName, "C"))

{

System.Threading.Thread.Sleep(5000);

}

}

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateDatabase - Created the database " + sDBName.ToString() + " in server " + sServerName.ToString(), ConsoleColor.Green);

bReturn = true;

}

else

{

sMsg = "Database exists";

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateDatabase - Creating DB " + sDBName.ToString() + " exists in server " + sServerName.ToString(), ConsoleColor.Yellow);

bReturn = true;

}

}

return bReturn;

}

catch (Exception e)

{ sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> bCreateDatabase - Error creating DB " + sDBName.ToString() + " in server " + sServerName.ToString() + " Error:" + sMsg.ToString(), ConsoleColor.Red);

return false;

}

}

 

public Boolean bDeleteDatabase(ref String sMsg, string sServerName = "", string sRGName = "", string sDBName = "", Boolean bCheck = true)

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

try

{

SqlManagementClient SqlClient = GetAccessClient("bDeleteDatabase");

Boolean bReturn = false;

if (bCheckIfServerExist(ref sMsg, sServerName,bCheck))

{

if (bCheckIfDatabaseExist(ref sMsg, sServerName, sRGName, sDBName, bCheck))

{

oClsWriteLog.WriteSomethingInConsole("-----------> bDeleteDatabase - Deleting the database " + sDBName.ToString() + " in Server:" + sServerName.ToString(), ConsoleColor.Magenta);

SqlClient.Databases.Delete(sRGName, sServerName, sDBName);

if (bCheck)

{

while (!bOperationFinished(ref sMsg, sServerName, sDBName, "D"))

{

System.Threading.Thread.Sleep(5000);

}

}

bReturn = true;

oClsWriteLog.WriteSomethingInConsole("-----------> bDeleteDatabase - Deleted the database " + sDBName.ToString() + " in Server: " + sServerName.ToString(), ConsoleColor.Green);

}

else

{ bReturn = true;

oClsWriteLog.WriteSomethingInConsole("-----------> bDeleteDatabase - Database doesn't exists " + sDBName.ToString() + " in Server: " + sServerName.ToString(), ConsoleColor.Green);

}

}

return bReturn;

}

catch (Exception e)

{

sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> bDeleteDatabase - Error deleting the database: " + sDBName.ToString() + " in Server: " + sServerName.ToString(), ConsoleColor.Red);

return false;

}

}

 

 

public Boolean bCheckIfServerExist( ref string sMsg, string sServerName = "",Boolean bCheck = true)

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

try

{

 

if(!bCheck)

{

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfServerExist - Skipping if the Server " + sServerName.ToString() + " exists.", ConsoleColor.White);

return true;

}

 

SqlManagementClient SqlClient = GetAccessClient("bCheckIfServerExist");

Boolean bReturn = false;

 

var List = SqlClient.Servers.List();

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfServerExist - Checking if the Server " + sServerName.ToString() + " exists.", ConsoleColor.White);

foreach (Microsoft.Azure.Management.Sql.Models.Server ServerItem in List)

{

if( ServerItem.Name.ToLower().Trim() == sServerName.ToLower().Trim())

{

sMsg = "Server already exist";

bReturn = true;

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfServerExist - Yeah! the Server " + sServerName.ToString() + " exists.", ConsoleColor.Green);

break;

}

}

if(!bReturn)

{

sMsg = "Server doesn't exists";

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfServerExist - The Server " + sServerName.ToString() + " doesn't exists.", ConsoleColor.Green);

}

 

return bReturn;

}

catch (Exception e)

{

sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfServerExist - Error Checking if the Server " + sServerName.ToString() + " exists. Error: " + sMsg.ToString(), ConsoleColor.Red);

return false;

}

}

 

public Boolean bCheckIfDatabaseExist(ref string sMsg, string sServerName = "", string sRGName = "", string sDatabaseName = "", Boolean bCheck = true, Boolean bReturnValue = true)

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

if (!bCheck)

{

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfDatabaseExist - Skipping if database: " + sDatabaseName.ToString() + " exists in server " + sServerName.ToString(), ConsoleColor.White);

return bReturnValue;

}

try

{

SqlManagementClient SqlClient = GetAccessClient("bCheckIfDatabaseExist");

Boolean bReturn = false;

 

var List = SqlClient.Databases.ListByServer(sRGName, sServerName);

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfDatabaseExist - Checking if database: " + sDatabaseName.ToString() + " exists in server " + sServerName.ToString(), ConsoleColor.White);

foreach (Microsoft.Azure.Management.Sql.Models.Database DatabaseName in List)

{

if (DatabaseName.Name.ToLower().Trim() == sDatabaseName.ToLower().Trim())

{

sMsg = "Database already exists";

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfDatabaseExist - The database: " + sDatabaseName.ToString() + " exists in server " + sServerName.ToString(), ConsoleColor.Green);

bReturn = true;

break;

}

}

return bReturn;

}

catch (Exception e)

{

sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> bCheckIfDatabaseExist - Error checking if database: " + sDatabaseName.ToString() + " exists in server " + sServerName.ToString() + " Error: " + sMsg, ConsoleColor.Red);

return false;

}

}

 

public Boolean bOperationFinished(ref String sMsg, string sServerName = "", string sDBName = "", String sOperation = "I")

{

ClsWriteLog oClsWriteLog = new ClsWriteLog();

try

{

Boolean bReturn = false;

ClsSecurity oClsSecurity = new ClsSecurity();

oClsSecurity.ServerName = "tcp:" + sServerName + ".database.windows.net,1433";

oClsSecurity.DBName = "master";

oClsSecurity.TypeExecution = "Management Operations";

 

C.SqlConnection oConnSource = new C.SqlConnection();

ClsRetryLogic oClsRetrySource = new ClsRetryLogic();

 

if (oClsRetrySource.HazUnaConexionConReintentos(oClsSecurity.GetConnectionString(), oConnSource, false,false))

{

 

if (sOperation == "D")

{

String sSyntaxOperation = "SELECT TOP 1 State FROM sys.dm_operation_status WHERE UPPER(convert(nvarchar(128),major_resource_id)) = '" + sDBName + "' AND operation = 'DROP DATABASE' ORDER BY start_time DESC";

String sSyntaxCheckSysDatabase = "SELECT TOP 1 name from sys.databases WHERE UPPER(name) = '" + sDBName + "'";

C.SqlCommand oCmdOperation = new C.SqlCommand(sSyntaxOperation, oConnSource);

oCmdOperation.CommandType = CommandType.Text;

C.SqlCommand oCmdSYSDB = new C.SqlCommand(sSyntaxCheckSysDatabase, oConnSource);

oCmdSYSDB.CommandType = CommandType.Text;

C.SqlDataReader oReaderOperation = oCmdOperation.ExecuteReader();

if (oReaderOperation.HasRows)

{

oReaderOperation.Read();

if (oReaderOperation.GetValue(0).ToString() == "2")

{

oReaderOperation.Close();

C.SqlDataReader oReaderSYSDB = oCmdSYSDB.ExecuteReader();

bReturn = !oReaderSYSDB.HasRows;

oReaderSYSDB.Close();

}

else

{

oReaderOperation.Close();

}

}

}

if (sOperation == "C")

{

String sSyntaxOperation = "SELECT TOP 1 State FROM sys.dm_operation_status WHERE UPPER(convert(nvarchar(128),major_resource_id)) = '" + sDBName + "' AND operation = 'CREATE DATABASE' ORDER BY start_time DESC";

String sSyntaxCheckSysDatabase = "SELECT TOP 1 name from sys.databases WHERE UPPER(name) = '" + sDBName + "' AND state=0";

 

C.SqlCommand oCmdOperation = new C.SqlCommand(sSyntaxOperation, oConnSource);

oCmdOperation.CommandType = CommandType.Text;

C.SqlCommand oCmdSYSDB = new C.SqlCommand(sSyntaxCheckSysDatabase, oConnSource);

oCmdSYSDB.CommandType = CommandType.Text;

C.SqlDataReader oReaderOperation = oCmdOperation.ExecuteReader();

if (oReaderOperation.HasRows)

{

oReaderOperation.Read();

if (oReaderOperation.GetValue(0).ToString() == "2")

{

oReaderOperation.Close();

C.SqlDataReader oReaderSYSDB = oCmdSYSDB.ExecuteReader();

bReturn = oReaderSYSDB.HasRows;

oReaderSYSDB.Close();

}

else

{

oReaderOperation.Close();

}

}

}

 

oConnSource.Close();

}

return bReturn;

}

catch (Exception e)

{

sMsg = "Error: " + e.Message;

oClsWriteLog.WriteSomethingInConsole("-----------> Checking the DB Error: " + sMsg, ConsoleColor.Red);

return false;

}

}

 

 

public SqlManagementClient GetAccessClient(String sOperation = "")

{

//WriteSomethingInConsole("-------------> GetAccessClient - Getting the client and Token for " + sOperation.ToString(), ConsoleColor.White);

var authContextUrl = "https://login.microsoftonline.com/tenant-id";

var authenticationContext = new AuthenticationContext(authContextUrl);

var credential = new ClientCredential("principalid", "secretid");

var result = authenticationContext.AcquireTokenAsync(resource: "https://management.core.windows.net/", clientCredential: credential).Result;

//var credentials = new Microsoft.Rest.TokenCredentials(result.AccessToken);

Microsoft.Rest.ServiceClientCredentials credentials = new Microsoft.Rest.TokenCredentials(result.AccessToken);

 

if (result == null)

{

throw new InvalidOperationException("-------------> GetAccessClient - Failed to obtain the JWT token for " + sOperation.ToString());

}

 

var client = new SqlManagementClient(credentials);

client.SubscriptionId = "subscriptionId";

//WriteSomethingInConsole("-------------> GetAccessClient - Token Obtained..for " + sOperation.ToString(), ConsoleColor.White);

return client;

}

}

}

 

 

 

 

 

 

 

Additionally, I developed this small C# code to capture all the messages.

 

 

 

using System.Collections.Generic;

using System.Linq;

using System.Text;

using System.Threading.Tasks;

 

namespace DotNetExample

{

class ClsWriteLog

{

public void WriteSomethingInConsole(String sText, System.ConsoleColor iColor)

{

System.ConsoleColor iColorTmp;

iColorTmp = Console.ForegroundColor;

Console.ForegroundColor = iColor;

Console.WriteLine(DateTime.Now.ToString() + " " + sText);

Console.ForegroundColor = iColorTmp;

}

}

}

 

 

 

 

 

 

 

 

 

 

Additionaly I used the following TSQL command to monitor all the operations an current status using SQL Server Management Studio:

 

 

 

 

 

SELECT * FROM sys.dm_operation_status ORDER BY start_time DESC

 

 

 

 

 

 

 

 

However, without running this special checking list, I used to receive error message as I mentioned before including others.

 

 

 

Enjoy!

 

Continue reading...