becky
becky

Reputation: 331

MicrosoftSqlAzureExecutionStrategy derived class: retry number varies

I'm using .Net 4.8 and EF6.5 with Microsoft.Data.SqlClient. I want to manage retries for my SQL Azure WinForms app. I have a class derived from MicrosoftSqlAzureExecutionStrategy to log the retries and to add an additional error code for testing purposes. When I check my logs there a 3 times more log entries than I would expect. When I delete the call to GetNextDelay(...) I even get more log entries.

What is the right way to configure a derived class from MicrosoftSqlAzureExecutionStrategy?

Why does the retry number vary (I used the default value, which should be 5)?

Here is my code:

public class MyStrategy : MicrosoftSqlAzureExecutionStrategy
{
    public static List<Exception> _exceptionsEncountered = new List<Exception>();

    public MyStrategy(bool reset)
    {
        if (reset) { _exceptionsEncountered.Clear(); }
    }

    protected override TimeSpan? GetNextDelay(Exception lastException)
    {        
     return base.GetNextDelay(lastException);
    }

    protected override bool ShouldRetryOn(Exception exception)
    {
        _exceptionsEncountered.Add(exception);
        var currentRetryCount = _exceptionsEncountered.Count - 1;
        var delay = GetNextDelay(exception);
        if (delay == null)
        {
            delay = new TimeSpan(0);
        }
        int errorCode = -1;
        if (exception is Microsoft.Data.SqlClient.SqlException)
        {     
            errorCode = (exception as Microsoft.Data.SqlClient.SqlException).Number;
        }        
        ErrorMessage($"ShouldRetryOn: retry Count: {currentRetryCount}, delay: {delay},  exception no.: {errorCode}, exception: {exception.Message}");
        
        // only for testing:
        if (errorCode == 11001) { return true; }

        return base.ShouldRetryOn(exception);
    }
}

public class DataContextConfiguration : MicrosoftSqlDbConfiguration
   {
       public DataContextConfiguration()
       {          
           SetProviderFactory(MicrosoftSqlProviderServices.ProviderInvariantName, SqlClientFactory.Instance);
           SetProviderServices(MicrosoftSqlProviderServices.ProviderInvariantName, MicrosoftSqlProviderServices.Instance);           
           /*** set execution/retry strategy of connections** */
           SetExecutionStrategy(MicrosoftSqlProviderServices.ProviderInvariantName, () => new MyStrategy(true));
       }
   }

[DbConfigurationType(typeof(DataContextConfiguration))] 
public partial class TestModel : DbContext
  { 
      public TestModel(string connectionString) : base(connectionString)
      {   
          Database.Log = sql => Debug.Write(sql);
          //avoid internal errors like Invalid object name 'dbo.__MigrationHistory'. 
          Database.SetInitializer<TestModel>(null);
      }
...
}

//function call:
 public string GetIDdata(string myid)
 {
     try
     {         
         using (var db = new TestModel(ConnectionString))
         {       
                 var query = from b in db.testing
                             where b.id == myid
                             select b; 
                 if (query.Count() == 0)
                 {
                     return String.Empty;
                 }
                 else
                 {
                    //process data
                 }
         }
     }
     catch (Exception ex)
     {         
         Helper.ErrorMessage(ex.Message);      
         return String.Empty;
     }
 }

This is my Log:

10:46:09.964||Error|ShouldRetryOn: retry Count: 0, delay: 00:00:00,  exception no.: 11001, exception: ...
10:46:40.739||Error|ShouldRetryOn: retry Count: 1, delay: 00:00:03.2390000,  exception no.: 11001, exception: ...
10:47:17.638||Error|ShouldRetryOn: retry Count: 2, delay: 00:00:16.0010000,  exception no.: 11001, exception: ...
10:47:47.356||Error|ShouldRetryOn: retry Count: 0, delay: 00:00:00,  exception no.: 11001, exception: ..
10:48:18.098||Error|ShouldRetryOn: retry Count: 1, delay: 00:00:03.2370000,  exception no.: 11001, exception: ..
10:48:55.303||Error|ShouldRetryOn: retry Count: 2, delay: 00:00:15.8020000,  exception no.: 11001, exception: ..
10:49:25.406||Error|ShouldRetryOn: retry Count: 0, delay: 00:00:00,  exception no.: 11001, exception: ..
10:49:56.162||Error|ShouldRetryOn: retry Count: 0, delay: 00:00:03.0840000,  exception no.: 11001, ..
10:50:33.410||Error|ShouldRetryOn: retry Count: 0, delay: 00:00:15.2000000,  exception no.: 11001, ..
10:50:33.410||Error|Maximum number of retries (5) exceeded while executing database operations with 'MyStrategy'. See inner exception for the most recent failure. 

When I delete the call to GetNextDelay(exception), my Log looks like this:

09:29:58.386||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:30:28.213||Error|ShouldRetryOn: retry Count: 1,  exception no.: 11001, exception: ...
09:33:05.262||Error|ShouldRetryOn: retry Count: 2,  exception no.: 11001, exception: ...
09:33:38.237||Error|ShouldRetryOn: retry Count: 3,  exception no.: 11001, exception: ...
09:34:15.466||Error|ShouldRetryOn: retry Count: 4,  exception no.: 11001, exception: ...
09:35:01.421||Error|ShouldRetryOn: retry Count: 5,  exception no.: 11001, exception: ...
09:35:31.228||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:36:01.022||Error|ShouldRetryOn: retry Count: 1,  exception no.: 11001, exception: ...
09:36:31.878||Error|ShouldRetryOn: retry Count: 2,  exception no.: 11001, exception: ...
09:37:04.808||Error|ShouldRetryOn: retry Count: 3,  exception no.: 11001, exception: ...
09:37:41.787||Error|ShouldRetryOn: retry Count: 4,  exception no.: 11001, exception: ...
09:38:27.710||Error|ShouldRetryOn: retry Count: 5,  exception no.: 11001, exception: ...
09:38:57.994||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:39:27.795||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:39:58.711||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:40:31.726||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:41:09.101||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...
09:41:55.337||Error|ShouldRetryOn: retry Count: 0,  exception no.: 11001, exception: ...

Does anyone have an explanation for this?

Shouldn't there be only 5 retry attempts?

Upvotes: 0

Views: 59

Answers (0)

Related Questions