Guida alla risoluzione dei problemi di SqlException: timeout scaduto alla connessione, in una situazione senza carico

StackOverflow https://stackoverflow.com/questions/1421978

Domanda

Ho un server che ospita un mio sito web a traffico quasi zero.
Alcune persone (& Lt; 20) entrano nel sito ogni giorno e alcuni lettori RSS sono abbonati ad alcuni feed che pubblichiamo.

Quasi ogni notte, un lettore RSS ci colpirà nel cuore della notte e otterrà un'eccezione che il sito Web non può connettersi a SQL Server a causa di un timeout nella connessione. I dettagli sono estremamente strani, quindi sto cercando un aiuto su quale potrebbe essere il problema, dal momento che non so più da dove cominciare a cercare.

Stiamo utilizzando ASP.Net MVC, Entity Framework e SQL Server 2008 su Windows Server 2008. La macchina è una scatola dedicata che abbiamo ottenuto da un provider non esattamente di livello superiore, quindi le cose potrebbero essere configurate in modo non ottimale, oppure chissà cos'altro.
La confezione è anche piuttosto piccola e ha solo 1 GB di RAM, ma dovrebbe richiedere il tipo di carico che abbiamo per ora ...

Sto copiando l'intero stack di chiamate di seguito, ma prima alcune delle cose che conosciamo:

  • L'errore si verifica sempre quando iTunes esegue una query sul nostro sito. Credo che questo non dovrebbe avere nulla a che fare con nulla, ma la verità è che lo otteniamo solo da iTunes. La mia ipotesi migliore è che ciò accada perché solo iTunes ci interroga a quell'ora della notte quando nessun altro ci sta colpendo.
  • Una delle nostre teorie è che SQL Server e IIS stanno lottando per la memoria, e uno di loro viene impaginato su disco per non essere utilizzato e quando qualcuno " lo sveglia " , impiega troppo tempo a leggere tutto dal disco in memoria. È qualcosa che potrebbe potenzialmente accadere? (Sto scartando questo tipo, dato che su SQL Server sembra un problema di progettazione se fosse possibile)
  • Ho anche pensato alla possibilità che stiamo perdendo connessioni, dal momento che potremmo non disporre in modo appropriato delle entità EF ( vedi la mia domanda qui ). Questa è l'unica cosa che ho trovato cercando su Google il problema. Sto scartando questo dato il carico estremamente basso che abbiamo.
  • Questo succede sempre durante la notte, quindi è molto probabile che qualcosa sia legato al fatto che non è successo nulla per un po '. Ad esempio, sono abbastanza sicuro che quando queste richieste arrivano, il processo del server web viene riciclato e si avvia / re-JIT su tutto. Il re-JITting non spiega il timeout SQL, tuttavia.

AGGIORNAMENTO: abbiamo allegato un profiler come suggerito, e ci è voluto un po 'di tempo prima che ci fosse una nuova eccezione. Queste sono le novità che conosciamo:

  • Far attaccare il profiler enormemente ha ridotto il numero di errori che abbiamo riscontrato. Infatti, dopo averne normalmente acquistati diversi al giorno, abbiamo dovuto attendere 3 o 4 giorni perché ciò accadesse UNA VOLTA. Una volta fermato il profiler, è tornato alla normale frequenza di errore (o anche peggio). Quindi il profiler ha alcuni effetti che nascondono questo problema in una certa misura, ma non completamente.
  • Osservando la traccia del profiler accanto al registro delle richieste IIS, esiste una corrispondenza 1-1 prevista tra richieste e query. Tuttavia, ogni tanto vedo MOLTE query in esecuzione che non hanno alcuna correlazione con il registro IIS. In effetti, proprio prima della registrazione dell'errore reale, ho ricevuto 750 query in un periodo di 3 minuti , tutte completamente estranee ai log di IIS. Il testo della query assomiglia al tipo di schifezza illeggibile che genera EF, e non sono tutti uguali e sembrano tutti come le query provenienti dal sito Web: stesso nome applicazione, utente, ecc. Per dare un'idea di quanto sia ridicolo è, il sito ha ricevuto circa 370 richieste IIS che hanno colpito il DB, nel corso di 2 giorni
  • Queste query inspiegabili non provengono dallo stesso ClientProcessID dei precedenti siti Web, sebbene possano ancora provenire dal sito Webe, se nel frattempo il processo è stato riciclato. C'è stata quasi un'ora di nessuna attività tra l'ultima query spiegata e la prima inspiegabile.
  • Una di queste lunghe serie di query che non so da dove provenissero è arrivata proprio prima dell'errore che ho registrato, quindi credo che questo sia l'indizio che dovremmo seguire.
  • Come mi aspettavo inizialmente, quando la query che ha generato l'errore è stata eseguita, proveniva da un ClientProcessID diverso da quello precedente, (8 minuti dopo il precedente inspiegabile e quasi esattamente un'ora dopo quella precedente di IIS ). Ciò significa, per me, che il processo operaio è stato effettivamente riciclato.
  • Questo è qualcosa che non capisco assolutamente. Il registro IIS mostra che un minuto prima della richiesta di errore, 4 erano perfettamente serviti, anche se le query per quelli non vengono affatto visualizzate nella traccia. In effetti, dopo quei 4 che sono andati bene, ho avuto 4 eccezioni lanciate in rapida successione, quei 4 ANCHE non compaiono nella traccia (il che ha senso dato che se ci fosse un Timeout in connessione la query non avrebbe mai dovuto essere eseguita, ma non vedo neanche i tentativi di connessione nella traccia)

Quindi, in breve, sono completamente all'oscuro di questo. Non riesco a trovare un motivo per quelle centinaia di query che vengono eseguite in rapida successione, ma credo che queste debbano avere a che fare con il problema.
Inoltre non so come diagnosticare i problemi di connessione ...
O come alla traccia di Profiler potrebbero mancare alcune query che, secondo IIS, sono andate bene ...

Qualche idea?

Queste sono le informazioni sull'eccezione: 

System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

System.Data.EntityException: The underlying provider failed on Open. ---> System.Data.SqlClient.SqlException: Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
   at System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection owningObject)
   at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
   at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
   at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFactory connectionFactory)
   at System.Data.SqlClient.SqlConnection.Open()
   at System.Data.EntityClient.EntityConnection.OpenStoreConnectionIf(Boolean openCondition, DbConnection storeConnectionToOpen, DbConnection originalConnection, String exceptionCode, String attemptedOperation, Boolean& closeStoreConnectionOnFailure)
   at System.Data.EntityClient.EntityConnection.OpenStoreConnectionIf(Boolean openCondition, DbConnection storeConnectionToOpen, DbConnection originalConnection, String exceptionCode, String attemptedOperation, Boolean& closeStoreConnectionOnFailure)
   --- End of inner exception stack trace ---
   at System.Data.EntityClient.EntityConnection.OpenStoreConnectionIf(Boolean openCondition, DbConnection storeConnectionToOpen, DbConnection originalConnection, String exceptionCode, String attemptedOperation, Boolean& closeStoreConnectionOnFailure)
   at System.Data.EntityClient.EntityConnection.Open()
   at System.Data.Objects.ObjectContext.EnsureConnection()
   at System.Data.Objects.ObjectQuery`1.GetResults(Nullable`1 forMergeOption)
   at System.Data.Objects.ObjectQuery`1.System.Collections.Generic.IEnumerable<T>.GetEnumerator()
   at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source)
   at System.Data.Objects.ELinq.ObjectQueryProvider.<GetElementFunction>b__1[TResult](IEnumerable`1 sequence)
   at System.Data.Objects.ELinq.ObjectQueryProvider.ExecuteSingle[TResult](IEnumerable`1 query, Expression queryRoot)
   at System.Data.Objects.ELinq.ObjectQueryProvider.System.Linq.IQueryProvider.Execute[S](Expression expression)
   at System.Linq.Queryable.FirstOrDefault[TSource](IQueryable`1 source)
   at MyProject.Controllers.SitesController.Feed(Int32 id) in C:\...\Controller.cs:line 38
   at lambda_method(ExecutionScope , ControllerBase , Object[] )
   at System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary`2 parameters)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary`2 parameters)
   at System.Web.Mvc.ControllerActionInvoker.<>c__DisplayClassa.<InvokeActionMethodWithFilters>b__7()
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethodFilter(IActionFilter filter, ActionExecutingContext preContext, Func`1 continuation)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethodWithFilters(ControllerContext controllerContext, IList`1 filters, ActionDescriptor actionDescriptor, IDictionary`2 parameters)
   at System.Web.Mvc.ControllerActionInvoker.InvokeAction(ControllerContext controllerContext, String actionName)
   at System.Web.Mvc.Controller.ExecuteCore()
   at System.Web.Mvc.MvcHandler.ProcessRequest(HttpContextBase httpContext)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Qualsiasi idea sarà enormemente apprezzata.

È stato utile?

Soluzione

Memoria insufficiente

Questo è molto probabilmente un problema di memoria, forse aggravato o innescato da altre cose, ma ancora intrinsecamente un problema di memoria. ci sono altre due (meno probabili) possibilità, che dovresti prima controllare ed eliminare (perché è facile farlo):

Possibilità di facile controllo:

  1. Potresti avere " Chiusura automatica " abilitato: la chiusura automatica può avere esattamente questo comportamento, tuttavia è raro che sia attivata. Per verificare ciò, nel SSMS fare clic con il tasto destro sul database dell'applicazione, selezionare & Quot; Proprietà & Quot ;, quindi selezionare & Quot; Opzioni & Quot; riquadro. Guarda il & Quot; Chiusura automatica & Quot; voce e assicurarsi che sia impostato su False. Controlla anche tempdb.

  2. I processi dell'agente SQL potrebbero essere la causa: controllare il registro cronologico dell'agente per vedere se ci sono stati processi in esecuzione in modo coerente durante gli eventi. Ricorda di controllare anche i lavori di manutenzione, poiché cose come Ricostruzione degli indici sono spesso citate come problemi di prestazioni mentre sono in esecuzione. Questi sono candidati improbabili ora, solo perché normalmente non sarebbero interessati dal Profiler.

Perché sembra un problema di memoria:

Se quelli non mostrano nulla, è necessario verificare la presenza di problemi di memoria. Sospetto che Memory sia la causa nel tuo caso perché:

  • Hai 1 GB di memoria: anche se tecnicamente è superiore al minimo per SQL Server, è molto inferiore a quello raccomandato per SQL Server e molto inferiore a ciò che nella mia esperienza è accettabile per la produzione, anche per un server caricato.

  • IIS e SQL Server sono in esecuzione nella stessa casella: ciò non è consigliato da solo, in gran parte a causa della contesa per la memoria risultante, ma con solo 1 GB di memoria risulta in IIS, il app, SQL Server, il sistema operativo e qualsiasi altra attività e / o manutenzione tutti in lotta per una memoria molto ridotta. Il modo in cui Windows gestisce questo è quello di dare memoria ai processi attivi allontanandolo in modo aggressivo dai processi non attivi. Potrebbero essere necessari molti secondi, o addirittura minuti, affinché un processo di grandi dimensioni come SQL Server recuperi abbastanza memoria per essere in grado di soddisfare completamente una richiesta in questa situazione.

  • Profiler ha eliminato il 90% del problema: questo è un grande indizio del fatto che la memoria è probabilmente il problema, perché in genere cose come Profiler hanno esattamente questo effetto su questo particolare problema: l'attività di Profiler mantiene SQL Server solo un piccolo bit sempre attivo. Spesso, questa è solo un'attività sufficiente per tenerla lontana dal & Quot del sistema operativo; scavenger & Quot; elenco, o almeno riduce in qualche modo il suo impatto.

Come verificare la memoria come colpevole:

  1. Disattiva il profiler: sta avendo un effetto Heisenberg sul problema, quindi devi disattivarlo o non sarai in grado di vedere il problema in modo affidabile.

  2. Esegui un monitor di sistema (perfmon.exe) da un'altra casella, che si connette in remoto al servizio di raccolta delle prestazioni sulla casella su cui sono in esecuzione SQL Server e IIS. puoi farlo più facilmente rimuovendo prima le tre statistiche predefinite (sono solo locali), quindi aggiungi le statistiche necessarie (sotto), ma assicurati di cambiare il nome del computer nel primo menu a discesa per connetterti al tuo SQL di dialogo.

  3. Invia i dati raccolti a un file creando un " Contatore Log " su perfmon. Se non hai familiarità con questo, la cosa più semplice da fare è probabilmente raccogliere i dati in un file separato da tabulazione o virgola che puoi aprire con Excel per analizzare.

  4. Configura il tuo perfmon per raccogliere in un file e aggiungere i seguenti contatori:

    - Processore \% Tempo processore [Totale]

    - PhysicalDisk \% Idle Time [ per ogni disco ]

    - PhysicalDisk \ Avg. Lunghezza coda disco [ per ciascun disco ]

    - Memoria \ Pagine / sec

    - Memoria \ Page Legge / sec

    - Memoria \ MByte disponibili

    - Interfaccia di rete \ Byte totali / sec [ per ciascuna interfaccia in uso ]

    - Process \% Processor Time [ vedi sotto ]

    - Process \ Page Faults / sec [ vedi sotto ]

    - Process \ Working Set [ vedi sotto ]

  5. Per i contatori di processi (sopra) si desidera includere il processo sqlserver.exe, tutti i processi IIS e tutti i processi applicativi stabili. Nota che funzionerà SOLO per & Quot; stable & Quot; processi. I processi che vengono continuamente ricreati secondo necessità, non possono essere catturati in questo modo perché non c'è modo di specificarli prima che esistano.

  6. Esegui questa raccolta su un file durante il periodo in cui si verifica il problema più frequentemente. Impostare l'intervallo di raccolta su un valore vicino a 10-15 secondi. (questo raccoglie molti dati, ma avrai bisogno di questa risoluzione per selezionare gli eventi separati).

  7. Dopo aver riscontrato uno o più incidenti, interrompere la raccolta e quindi aprire il file di dati raccolti con Excel. Probabilmente dovrai riformattare la colonna del timestamp per renderla utile e mostrare ore e minuti. Usa il tuo registro IIS per trovare l'ora esatta degli incidenti, quindi guarda i dati perfmon per vedere cosa stava succedendo prima e dopo l'incidente. In particolare, vuoi vedere se il suo set di lavoro era piccolo prima e grande dopo, con un sacco di pagine difettose nel mezzo. Questo è il segno più chiaro di questo problema.

SOLUZIONI:

Separare IIS e SQL Server in due caselle diverse (preferito) oppure aggiungere più memoria alla casella. Penso che 3-4 GB dovrebbero essere un minimo.

Che ne dici di quella strana roba EF?

Il problema qui è che molto probabilmente è periferico o contribuisce solo al tuo problema principale. Ricorda che Profiler ha fatto sparire il 90% dei tuoi incidenti, quindi ciò che rimane, potrebbe essere un problema diverso o potrebbe essere solo il aggravatore più estremo del problema. A causa del suo comportamento, immagino che stia ciclando la sua cache o che ci sia qualche altra manutenzione in background dei processi del server delle applicazioni.

Altri suggerimenti

Vorrei confrontare il timestamp del timeout con il tempo di esecuzione del backup notturno. Se coincidono, puoi impostare il tuo feed RSS su statico per quel momento.

Un'altra cosa da provare (anche se non è esattamente una risposta) è eseguire immediatamente sp_who quando ricevi un'eccezione di timeout. Non catturerà tutto (il processo offensivo potrebbe essere eseguito al momento dell'esecuzione) ma potresti essere fortunato.

Puoi anche avviare SQL Profiler quando torni a casa per la notte e svolgi l'attività la mattina successiva se vedi di nuovo l'errore. Assicurati solo di non eseguirlo dal server stesso (sono abbastanza sicuro che ti ricordi questo quando si avvia).

MODIFICA: indirizzare l'aggiornamento.

EF sta aggiornando / creando la sua cache? Potrebbe spiegare l'abbondanza di query in una volta e il motivo per cui nessuna query ha avuto esiti positivi nel database in seguito.

A parte questo, sembra che tu abbia un heisenbug. L'unica cosa che posso pensare di aggiungere è molto più registrazione (in un file o nel registro eventi).

Profuma di una cosa stretta che corre allo stesso tempo. Come dice RBarryYoung ... qualche backup notturno o potrebbe essere qualcos'altro Hai accesso root al server? Riesci a vedere i crontab?

Potrebbe essere un plug-in di indicizzazione di testo completo sopra il server SQL che esegue le sue procedure di reindicizzazione vicino al momento in cui si verificano i problemi?

Nel mio caso, quando ho installato sqlserver 2008 r2 sp3, il problema scompare.

Server: Windows 7 + SqlServer 2008 R2 (edizione per sviluppatori) client: Raspberrypi 3B +, Asp.net Core + EF Core

Autorizzato sotto: CC-BY-SA insieme a attribuzione
Non affiliato a StackOverflow
scroll top