ASP.NET Zone

Hallo zusammen

Wir haben hier eine Web-Applikation, die auf einen neuen Server umziehen soll. Beim neuen Server handelt es sich um einen Win2k8 Server mit MS SQL 2008 Server installiert. Die Applikation (inkl. DB) ist zum Testen bereits auf dem neuen Server. Es funktioniert inzwischen auch alles, wie es sollte, bis auf eine Ausnahme: Wird die App rezykliert, läuft anschliessend die erste DB-Abfrage jeweils in ein Timeout (in seltenen Fällen kommt statt eines Timeouts auch die Fehlermeldung, dass die Abfrage fehlerhaft sei). Alle weiteren Zugriffe funktionieren danach wieder problemlos bis zum nächsten Recycle...

Hat jemand eine Idee, woran das liegen könnte, resp. wie man das beheben könnte?

Vielen Dank im Voraus.
Urs

Hallo Urs,

harti20:

Wir haben hier eine Web-Applikation, die auf einen neuen Server umziehen soll. Beim neuen Server handelt es sich um einen Win2k8 Server mit MS SQL 2008 Server installiert. Die Applikation (inkl. DB) ist zum Testen bereits auf dem neuen Server. Es funktioniert inzwischen auch alles, wie es sollte, bis auf eine Ausnahme: Wird die App rezykliert, läuft anschliessend die erste DB-Abfrage jeweils in ein Timeout (in seltenen Fällen kommt statt eines Timeouts auch die Fehlermeldung, dass die Abfrage fehlerhaft sei). Alle weiteren Zugriffe funktionieren danach wieder problemlos bis zum nächsten Recycle...

ich persönlich stelle solche Anwendungen für gewöhnlich so ein, dass der Application Pool nicht nach einem Timeout, sondern kontrolliert, bspw. um 3 Uhr nachts, einmal recyclet wird. Der Timeoutwert des Application Pools ist entsprechend hoch, damit das nicht doch vorher greift.

Anschließend wird ein Request auf die Anwendung per Batchjob gestartet (Task Scheduler o.ä.), damit wird die Anwendung wieder kompiliert und hochgefahren. Nachfolgende Requests sind dann gewohnt schnell.

Ich denke nicht, dass die DB Abfrage selbst in ein Timeout läuft, es sei denn, ihr instantiiert die Connection einmal pro Application (ggfs. als Shared, static, ...). Das sollte man aber tunlichst unterlassen.

Wenn das mit dem kontrollierten Recyclen nicht hilft, poste doch bitte ein paar mehr Details der Vorgehensweise (Aufbau der Verbindung wann, wo und wie. Dauer des ersten Verbindungsaufbaus zum DB Server, ...)

---

--
Gruß, Stefan Falz
Microsoft MVP - Visual Developer ASP/ASP.NET
ASP.NET Consulting, Development, Coaching

ASP.NET Zone - Leitfaden für gute Postings

Xtopia 2008 - Gewinnspiel / Expression Studio und Xtopia Eintrittskarten zu gewinnen

Hallo Stefan

Vielen Dank für die Antwort. Ich habe die Anwendung wie von Dir beschrieben angepasst und werde mal schauen, ob das ausreicht.

Gruss,
Urs

Leider haben wir das Problem noch nicht lösen können. Wir sind aber allmählich dabei, das ganze etwas einzugrenzen.
Ich lasse zum Testen im Login-Form sehr detaillierte Informationen in ein Log-File schreiben. Dabei ist mir aufgefallen, dass er in unregelmässigen Abständen ein etwas merkwürdiges Verhalten an den Tag legt:



frmLogin.aspx
-------------

private void Page_Load(object sender, System.EventArgs e)
  {
   App.WriteNewLog("Information: ", "frmLogin.Page_Load()", "Start Page_Load()", this.Session.SessionID);
   if (!IsPostBack)
   {
    SetupForm();
   }
   App.WriteNewLog("Information: ", "frmLogin.Page_Load()", "End Page_Load()", this.Session.SessionID);
  }

  private void SetupForm()
  {
   App.WriteNewLog("Information: ", "frmLogin.SetupForm()", "Start of Method", this.Session.SessionID);
   App.UserLogout(this.Session);
   App.WriteNewLog("Information: ", "frmLogin.SetupForm()", "End of Method", this.Session.SessionID);
  }

App.cs
------

  public static bool UserLogout(HttpSessionState aSession)
  {
   App.WriteNewLog("Information: ", "App.UserLogout()", "Next step: session.Clear()", aSession.SessionID);
   aSession.Clear();
   App.WriteNewLog("Information: ", "App.UserLogout()", "Next step: session.RemoveAll()", aSession.SessionID);
   aSession.RemoveAll();
   App.WriteNewLog("Information: ", "App.UserLogout()", "Next step: session.Abandon()", aSession.SessionID);
   aSession.Abandon();
   App.WriteNewLog("Information: ", "App.UserLogout()", "Next step: FormsAuthentication.SignOut()", aSession.SessionID);
   FormsAuthentication.SignOut();
   App.WriteNewLog("Information: ", "App.UserLogout()", "End of method", aSession.SessionID);
   return true;
  }

global.asax
-----------

  protected void Session_End(Object sender, EventArgs e)
  {
   App.WriteNewLog("Information: ", "global.asax Session_End()", "Start of Session_End()", this.Session.SessionID);
   App.decrementSessionCounter();
   App.WriteNewLog("Information: ", "global.asax Session_End()", "End of Session_End()", this.Session.SessionID);
  }

Die Einträge im dabei erstellten Log sehen dann wie folgt aus (aber wie erwähnt nicht jedes Mal, sondern nur von Zeit zu Zeit):

24.05.2011 14:01:13: Information:  global.asax Session_Start(); Start of Session_Start(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  global.asax Session_Start(); End of Session_Start(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  frmLogin.Page_Load(); Start Page_Load(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  frmLogin.SetupForm(); Start SetupForm(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  App.UserLogout(); Next step: session.Clear(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  App.UserLogout(); Next step: session.RemoveAll(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  App.UserLogout(); Next step: session.Abandon(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  App.UserLogout(); Next step: FormsAuthentication.SignOut(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  App.UserLogout(); End of UserLogout(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  frmLogin.SetupForm(); End of SetupForm(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:13: Information:  frmLogin.Page_Load(); End Page_Load(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:34: Information:  global.asax Session_End(); Start of Session_End(); SessionID: 'ezapidrqidtczh23khpvdgay'
24.05.2011 14:01:34: Information:  global.asax Session_End(); End of Session_End(); SessionID: 'ezapidrqidtczh23khpvdgay'

Was mich nun irritiert ist der Zeitunterschied zwischen den beiden fett markierten Einträgen, da im Form nach der Methode Page_Load() nichts mehr aufgerufen wird. Der dazu passende Eintrag im IIS-Log hat als Zeitpunkt 14:01:34 und als Time-Taken eine Dauer von 21010 ms. Ebenfalls kommt es von Zeit zu Zeit (auch wieder in unregelmässigen Abständen) bei DB-Abfragen beim Versuch, die Connection aufzubauen, zu einem Timeout.

Weiss evt. jemand, woran das liegen könnte, resp. wo wir noch nach einem Fehler suchen könnten?
Vielen Dank im Voraus.

Gruss,
Urs

Der Fehler ist endlich gefunden

Der Ursache auf die Schliche gekommen sind wir, als wir mal zum Testen im DB-Connection-String den Wert für "Data Source" von "(local)" auf die IP des Servers geändert haben. Danach liefen alle Abfragen problemlos und ohne Timeout durch. Nach einer Weile haben wir dann herausgefunden, dass beim Aufsetzen des Servers offenbar jemand den Servernamen in der Hosts-Datei eingetragen hatte. Da jedoch nachträglich die IP des Servers geändert hatte, zeigte jener Eintrag auf eine nicht mehr korrekte Adresse...

Gruss,
Urs