2017-02-23 1 views
1

Unten ist ein Bild von einigen Profiling mit Azure Application Insights. Es kommt von der Ausführung dieser einfachen Anfrage:Entity Framework 6 - Gesperrte Zeit Warten auf eine Verbindung

public HttpResponseMessage Login(LoginRequest loginRequest) 
     { 
      var t = new DependencyTracker(); 
      using (var context = t.TrackDependency(() => new SocialDbContext(), "NewContext")) 
      { 
       var user = t.TrackDependency(() => context.Users.AsNoTracking().SingleOrDefault(x => x.Email == loginRequest.Id || x.Name == loginRequest.Id), "GetUser"); 
       if (user == null) return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.WrongCredentials), "WrongCredentialsUser"); 
       var sid = t.TrackDependency(() => context.IdMappers.AsNoTracking().SingleOrDefault(x => x.Provider == "custom" && x.UserId == user.Id)?.Sid, "GettingSid"); 
       var account = t.TrackDependency(() => context.Accounts.AsNoTracking().SingleOrDefault(a => a.Id == sid), "GettingAccount"); 
       if (account == null) return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.WrongCredentials), "WrongCredentialsAccount"); 
       var incoming = t.TrackDependency(() => Hash(loginRequest.Password, account.Salt), "Hash"); 
       var isLoginOk = t.TrackDependency(() => SlowEquals(incoming, account.SaltedAndHashedPassword), "SlowEquals"); 
       if (isLoginOk && account.TempPasswordExpiry != null) 
       { 
        if (DateTimeOffset.Now.CompareTo(account.TempPasswordExpiry.Value) > 0) 
         return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.WrongCredentials), "WrongCredentialsPassword"); 
        return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.TemporaryPassword), "WrongCredentialsExpiredTempPassword"); 
       } 
       return isLoginOk 
        ? t.TrackDependency(() => SendToken(user.Id, sid), "SendToken") 
        : t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.Unauthorized, ApiError.WrongCredentials), "WrongCredentialsPassword"); 
      }   
     } 

Es gibt 3 SingleOrDefault Anrufe. In den Profiler-Ergebnissen sehe ich diese 3 Aufrufe.

  1. Die erste nimmt 3325ms (3017ms für die Verbindung wartet)
  2. Die zweite nimmt 2356ms (2349ms für die Verbindung wartet)
  3. Dann nimmt der letzte 0,28 ms



Was sind diese unglaublich langen Wartezeiten für die Verbindung?
Was verursacht sie und wie man davon fährt?

Entity Framework profiling

trace

UPDATE

Ich kann mich irren, aber ich glaube, ich weiß, was in einer Mischung aus verzögertes Laden geschieht und Sperre auf Metdata von that line wie in this documentation erläutert.

Konto benötigt sid, aber es hat die Metadaten gesperrt. Also wartet Sid. Dann benötigt sid einen Benutzer, aber es hat die Metadaten gesperrt. Also wartet der Benutzer. Dann wird der Benutzer ausgeführt, dann sid dann account.
Obwohl ich hätte gedacht, dass user == null und .Sid hätte die Ausführung erzwungen.

Gibt es eine Möglichkeit, faule Ladevorgänge zu aktivieren, um zu testen, was ich sage?

UPDATE 2

ich mit this.Configuration.LazyLoadingEnabled = false; in meinem Zusammenhang Ctor gerade versucht, aber das Problem bleibt :-(

Bitte beachte, dass ich das Problem nur alle 5 Minuten oder so wiedergeben kann. dazwischen scheint es einige Caching ist als die Abfragen sofort ausgeführt werden.

UPDATE 3

ich den Code mit einer Abfrage statt drei ersetzt:

public HttpResponseMessage Login(LoginRequest loginRequest) 
     { 
      var t = new DependencyTracker(); 
      using (var context = t.TrackDependency(() => new SocialDbContext(), "NewContext")) 
      { 
       var query = from a in context.Users 
          join b in context.IdMappers on a.Id equals b.UserId 
          join c in context.Accounts on b.Sid equals c.Id 
          where b.Provider == "custom" && (a.Email == loginRequest.Id || a.Name == loginRequest.Id) 
          select new { Sid = c.Id, c.Salt, c.SaltedAndHashedPassword, c.TempPasswordExpiry, UserId = a.Id }; 

       var account = t.TrackDependency(() => query.SingleOrDefault(), "GettingAccount"); 
       if (account == null) return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.WrongCredentials), "WrongCredentialsAccount"); 

       var incoming = t.TrackDependency(() => Hash(loginRequest.Password, account.Salt), "Hash"); 
       var isLoginOk = t.TrackDependency(() => SlowEquals(incoming, account.SaltedAndHashedPassword), "SlowEquals"); 
       if (isLoginOk && account.TempPasswordExpiry != null) 
       { 
        if (DateTimeOffset.Now.CompareTo(account.TempPasswordExpiry.Value) > 0) 
         return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.WrongCredentials), "WrongCredentialsPassword"); 
        return t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.BadRequest, ApiError.TemporaryPassword), "WrongCredentialsExpiredTempPassword"); 
       } 
       return isLoginOk 
        ? t.TrackDependency(() => SendToken(account.UserId, account.Sid), "SendToken") 
        : t.TrackDependency(() => Request.CreateResponse(HttpStatusCode.Unauthorized, ApiError.WrongCredentials), "WrongCredentialsPassword"); 
      } 
     } 

Aber die Frage bleibt, auch wenn nur noch eine Wartezeit gibt.
Aber wieder passiert es nur alle 5 Minuten.
Hinweis: Ich kann es nicht lokal reproduzieren, es passiert nur auf Azure.

UPDATE 4

Die Frage bleibt, selbst wenn eine gespeicherte Prozedur durch den Kontext aufgerufen wird. Ich nehme an, dass es nicht mit dem Abfrageplan zusammenhängt.

Was ich nicht verstehe, ist, dass das Problem auch bleibt, auch wenn ich die gespeicherte Prozedur mit einem SqlCommand rufen daher whithout Entity Framework ...

UPDATE 5

Dies ist kein Entity-Framework-Problem. Das Problem wartet auf die SQL-Verbindung. Ob mit EF oder mit SqlCommand die gleiche langsame Wartezeit tritt alle 5 Minuten auf. Ich schließe das Problem und öffne ein neues mit der entsprechenden Frage.

Antwort

0

Dies ist kein Entity-Framework-Problem. Das Problem wartet auf die SQL-Verbindung. Ob mit EF oder mit SqlCommand die gleiche langsame Wartezeit tritt alle 5 Minuten auf.