Loggare le query più lente con Entity Framework

di Stefano Mostarda, in LINQ, Entity Framework,

La stragrande maggioranza dei sistemi lavora con dati e quindi è normale che l'accesso al database rivesta un ruolo fondamentale nelle performance. Quando vogliamo ottimizzare le performance, dobbiamo sapere prima di tutto quali sono le query più lente così che possiamo ottimizzarle se possibile. Per scoprire le query più lente, possiamo ricorrere ad un interceptor che verifica il tempo di esecuzione della query e logga quelle che vanno oltre un certo limite. Nel prossimo esempio vediamo come creare questo interceptor.

public class SlowCommandsInterceptor(ILogger<SlowCommandsInterceptor> Logger) : 
  DbCommandInterceptor
{
  private const int _limit = 300;

  public override ValueTask<DbDataReader> ReaderExecutedAsync(DbCommand command, 
    CommandExecutedEventData eventData, DbDataReader result, 
    CancellationToken cancellationToken = default)
  {
    Check(command, eventData);
    return base.ReaderExecutedAsync(command, eventData, result, cancellationToken);
  }

  public override DbDataReader ReaderExecuted(DbCommand command, 
    CommandExecutedEventData eventData, DbDataReader result)
  {
    Check(command, eventData);
    return base.ReaderExecuted(command, eventData, result);
  }

  public override ValueTask<int> NonQueryExecutedAsync(DbCommand command, 
    CommandExecutedEventData eventData, int result, CancellationToken cancellationToken = default)
  {
    Check(command, eventData);
    return base.NonQueryExecutedAsync(command, eventData, result, cancellationToken);
  }

  public override int NonQueryExecuted(DbCommand command, 
    CommandExecutedEventData eventData, int result)
  {
    Check(command, eventData);
    return base.NonQueryExecuted(command, eventData, result);
  }

  public override object? ScalarExecuted(DbCommand command, 
    CommandExecutedEventData eventData, object? result)
  {
    Check(command, eventData);
    return base.ScalarExecuted(command, eventData, result);
  }

  public override ValueTask<object?> ScalarExecutedAsync(DbCommand command, 
    CommandExecutedEventData eventData, object? result, CancellationToken cancellationToken = default)
  {
    Check(command, eventData);
    return base.ScalarExecutedAsync(command, eventData, result, cancellationToken);
  }

  private void Check(DbCommand command, CommandExecutedEventData eventData)
  {
    if (eventData.Duration.TotalMilliseconds > _limit)
    {
      Logger.LogWarning($"Slow Command Detected. TotalMilliSeconds: {eventData.Duration.TotalMilliseconds} - 
        Command: {command.CommandText}  ");
    }
  }
}

Il codice è molto semplice, dopo ogni comando chiamiamo il metodo Check. All'interno di questo metodo, verifichiamo il tempo di esecuzione del comando SQL e se supera i 300 millisecondi allora inviamo un warning al sistema di logging oltre al comando SQL. Il solo comando SQL può non bastare in quanto non è affatto facile risalire dal codice SQL alla query LINQ che lo ha generato. Per questo motivo è sempre bene usare i metodi TagWith o TagWithCallSite che permettono di aggiungere commenti al codice SQL generato utili per risalire alla query LINQ originale.

Commenti

Visualizza/aggiungi commenti

| Condividi su: Twitter, Facebook, LinkedIn

Per inserire un commento, devi avere un account.

Fai il login e torna a questa pagina, oppure registrati alla nostra community.

Approfondimenti

I più letti di oggi