Aide au dépannage de SqlException: le délai d'attente a expiré lors de la connexion, dans une situation de non-chargement

Question

J'ai un serveur hébergeant l'un de mes sites sur lesquels le trafic est presque nul.
Quelques personnes (& Lt; 20) accèdent au site tous les jours et quelques lecteurs RSS sont abonnés à certains flux que nous publions.

Presque toutes les nuits, un lecteur RSS nous contacte au milieu de la nuit et obtient une exception selon laquelle le site Web ne peut pas se connecter à SQL Server en raison d'un délai d'expiration de la connexion. Les détails sont extrêmement bizarres, alors je cherche de l'aide sur ce qui pourrait être le problème, car je ne sais plus par où commencer.

Nous utilisons ASP.Net MVC, Entity Framework et SQL Server 2008 sur Windows Server 2008. La machine est une boîte dédiée que nous avons obtenue d'un fournisseur pas tout à fait supérieur; les éléments peuvent donc être configurés de manière non optimale. qui sait quoi d'autre.
La boîte est également assez petite et ne contient que 1 Go de RAM, mais elle devrait prendre le type de charge que nous avons pour le moment ...

Je copie la pile d'appels complète ci-dessous, mais nous connaissons tout d'abord certaines des choses que nous connaissons:

• L'erreur se produit toujours lorsque iTunes interroge notre site. Je pense que cela ne devrait avoir rien à voir avec rien, mais la vérité est que nous ne l'obtenons qu'iTunes. Ma meilleure hypothèse est que cela se produit car seul iTunes nous interroge à cette heure de la nuit où personne ne nous frappe.
• L’une de nos théories est que SQL Server et IIS se battent pour la mémoire, et l’une d’entre elles est paginée sur le disque parce qu’elle n'est pas utilisée et quand & "la réveille &"; , il faut trop de temps pour tout lire du disque dans la mémoire. Est-ce quelque chose qui pourrait potentiellement arriver? (Je suis en quelque sorte en train d’écarter cela car cela ressemblerait à un problème de conception dans SQL Server si cela était possible)
• J'ai aussi pensé à la possibilité que nous fassions des fuites de connexions, car nous risquons de ne pas éliminer correctement les entités EF ( voir ma question ici ). C'est la seule chose que j'ai pu trouver en googlant le problème. Je rejette ceci étant donné la charge extrêmement faible que nous avons.
• Cela se passe toujours la nuit, il est donc fort probable que quelque chose soit lié au fait que rien ne s'est passé pendant un moment. Par exemple, je suis à peu près sûr que lorsque ces demandes ont abouti, le processus du serveur Web a été recyclé et il a tout recommencé. Le re-JITting n'explique pas le délai d'attente SQL, cependant.

MISE À JOUR: Nous avons associé un profileur, comme suggéré, et il a fallu un certain temps avant qu'une nouvelle exception ne soit créée. Voici les nouvelles informations que nous connaissons:

• Le fait d’attacher le profileur énormément a réduit le nombre d’erreurs que nous avons générées. En fait, après en avoir pris plusieurs par jour, nous avons dû attendre 3 ou 4 jours pour que cela se produise UNE FOIS. Une fois que nous avons arrêté le profileur, il est revenu à la fréquence d'erreur normale (ou même pire). Le profileur a donc un effet masquant ce problème dans une certaine mesure, mais pas complètement.
• L'examen de la trace du profileur en regard du journal des demandes IIS indique une correspondance 1-1 attendue entre les demandes et les requêtes. Cependant, de temps en temps, je vois BEAUCOUP de requêtes en cours d’exécution qui n’ont aucune corrélation avec le journal IIS. En fait, juste avant que le bogue réel ne soit enregistré, j'ai reçu 750 requêtes sur une période de 3 minutes , toutes sans aucun lien avec les journaux IIS. Le texte de la requête ressemble au genre de merde illisible que EF génère, et ils ne sont pas tous identiques, ils ressemblent tous aux requêtes provenant du site Web: Same ApplicationName, User, etc. Pour donner une idée de la ridicule C’est que le site a reçu environ 370 demandes IIS qui ont atteint la base de données, au cours de 2 jours
.
• Ces requêtes inexpliquées ne provenaient pas du même ClientProcessID que celles du site Web précédent, bien qu'elles puissent toujours provenir du site Web.e, si le processus a été recyclé entre-temps. Il restait presque une heure sans activité entre la dernière requête expliquée et la première inexpliquée.
• Une de ces longues séries de questions dont je ne sais pas d'où elles viennent vient juste avant que l'erreur soit enregistrée, donc je crois que c'est l'indice que nous devrions suivre.
• Comme je m'y attendais à l'origine, lorsque la requête à l'origine de l'erreur a été exécutée, elle provenait d'un ClientProcessID différent du précédent (8 minutes plus tard que le précédent non expliqué, et presque exactement une heure plus tard que le précédent IIS). ). Pour moi, cela signifie que le processus de travail a bien été recyclé.
• C'est quelque chose que je ne comprends absolument pas. Le journal IIS indique qu’une minute avant les demandes d’erreur, 4 étaient parfaitement servies, bien que les requêtes pour celles-ci ne soient pas affichées du tout dans la trace. En fait, après ces 4 qui se sont bien déroulés, j'ai eu 4 exceptions jeté successivement, ces 4 AUSSI n'apparaissent pas dans la trace (ce qui est logique, car s'il y avait eu un Timeout en connexion, la requête n'aurait jamais dû être exécutée, mais je ne vois pas non plus les tentatives de connexion dans la trace)

Donc, en bref, je n’ai aucune idée de cela. Je ne trouve pas de raison pour ces centaines de requêtes qui sont rapidement exécutées, mais je crois que celles-ci doivent avoir un lien avec le problème.
Je ne sais pas non plus comment diagnostiquer les problèmes de connexion ...
Ou comment la trace de Profiler peut manquer quelques requêtes qui, selon IIS, ont bien fonctionné ...

Des idées?

Voici les informations sur l'exception:

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)

Toutes les idées seront extrêmement appréciées.

Answer 1

Mémoire insuffisante

C’est très probablement un problème de mémoire, peut-être aggravé ou déclenché par d’autres choses, mais reste en soi un problème de mémoire. il existe deux autres possibilités (moins probables) que vous devriez vérifier et éliminer en premier (parce que c'est facile à faire):

Facilité de vérification:

1. Il se peut que vous ayez " Fermeture automatique " enabled: la fermeture automatique peut avoir exactement ce comportement, mais il est rare qu’elle soit activée. Pour vérifier cela, dans SSMS, cliquez avec le bouton droit de la souris sur la base de données de votre application, sélectionnez & "Propriétés &", Puis sélectionnez la & "Options &"; vitre. Regardez le & Quot; Fermeture automatique & Quot; entrée et assurez-vous qu’il est défini sur False. Vérifiez également tempdb.

2. Les travaux de l'agent SQL peuvent en être la cause: consultez l'historique de l'agent pour vérifier si des travaux sont toujours en cours d'exécution pendant les événements. N'oubliez pas de vérifier également les travaux de maintenance, car des éléments tels que la reconstruction d'index sont souvent cités comme des problèmes de performances lors de leur exécution. Ce sont des candidats peu probables à présent, uniquement parce qu'ils ne seraient normalement pas affectés par le profileur.

Pourquoi cela ressemble à un problème de mémoire:

Si cela ne montre rien, vérifiez les problèmes de mémoire. Je soupçonne que la mémoire est la cause dans votre cas parce que:

• Vous avez 1 Go de mémoire: bien que ce soit techniquement supérieur au minimum requis pour SQL Server, il est bien inférieur à celui recommandé pour SQL Server, et bien inférieur à ce qui, selon mon expérience, est acceptable pour la production, même à la légère serveur chargé.

• Vous exécutez IIS et SQL Server sur la même boîte: cela n’est pas recommandé en soi, en grande partie à cause du conflit de mémoire qui en résulte, mais avec seulement 1 Go de mémoire dans IIS, le l’application, SQL Server, le système d’exploitation et toute autre tâche et / ou maintenance qui luttent pour très peu de mémoire. La façon dont Windows gère cela est de donner de la mémoire aux processus actifs en l'éloignant de manière agressive des processus non actifs. Cela peut prendre plusieurs secondes, voire quelques minutes, à un processus volumineux tel que SQL Server de récupérer suffisamment de mémoire pour pouvoir traiter complètement une requête dans cette situation.

• Profiler a résolu 90% du problème: c’est un indice important que la mémoire est probablement le problème, car généralement, des choses comme Profiler ont exactement cet effet sur ce problème particulier: la tâche de Générateur de profils garde le serveur SQL Server. juste un petit peu actif tout le temps. Fréquemment, il s’agit simplement d’une activité suffisante pour le garder en dehors du & "Scavenger &" Du système d’exploitation. liste, ou du moins réduit quelque peu son impact.

Vérification de la mémoire en tant que coupable:

1. Désactiver le profileur: il a un effet Heisenberg sur le problème. Vous devez donc l'éteindre sinon vous ne pourrez pas voir le problème de manière fiable.

2. Exécutez un Moniteur système (perfmon.exe) à partir d'une autre boîte, qui se connecte à distance au service de collecte de parfum sur la boîte sur laquelle SQL Server et IIS sont exécutés. vous pouvez le faire facilement en supprimant d’abord les trois statistiques par défaut (locales uniquement), puis en ajoutant les statistiques nécessaires (ci-dessous), mais veillez à modifier le nom de l’ordinateur dans le premier menu déroulant pour vous connecter à votre code SQL. boîte.

3. Envoyez les données collectées dans un fichier en créant un " journal de compteur " sur perfmon. Si cela ne vous est pas familier, la solution la plus simple consiste probablement à collecter les données dans un fichier séparé par des virgules que vous pouvez ouvrir avec Excel pour l'analyse.

4. Configurez votre perfmon pour la collecte dans un fichier et ajoutez-y les compteurs suivants:

   - Processeur \% Temps processeur [Total]

   - Disque physique \% temps d'inactivité [ pour chaque disque ]

   - Disque physique \ Avg. Longueur de la file d'attente de disque [ pour chaque disque ]

   - Mémoire \ Pages / s

   - Mémoire \ Page lit / s

   - Mémoire \ Mo disponibles

   - Interface réseau \ Total d'octets / s [ pour chaque interface utilisée ]

   - Processus \% Temps processeur [ voir ci-dessous ]

   - Traitement \ Défauts de page / s [ voir ci-dessous ]

   - Processus \ Ensemble de travail [ voir ci-dessous ]

5. Pour les compteurs de processus (ci-dessus), vous souhaitez inclure le processus sqlserver.exe, tous les processus IIS et tous les processus d'application stables. Notez que cela fonctionnera UNIQUEMENT pour & Quot; stable & Quot; processus. Les processus qui sont continuellement recréés en fonction des besoins ne peuvent pas être capturés de cette façon car il n’existe aucun moyen de les spécifier avant qu’ils n'existent.

6. Exécutez cette collection dans un fichier pendant que le problème se produit le plus souvent. Définissez un intervalle de collecte proche de 10-15 secondes. (cela collecte beaucoup de données, mais vous aurez besoin de cette résolution pour choisir les événements séparés).

7. Après avoir eu un ou plusieurs incidents, arrêtez la collecte, puis ouvrez votre fichier de données collecté avec Excel. Vous devrez probablement reformater la colonne timestamp pour qu'elle soit visible et afficher les heures, les minutes et les secondes. Utilisez votre journal IIS pour trouver l'heure exacte des incidents, puis examinez les données perfmon pour voir ce qui se passait avant et après l'incident. En particulier, vous voulez voir si son ensemble de travail était petit avant et grand après, avec beaucoup de défauts de page entre les deux. C’est le signe le plus clair de ce problème.

SOLUTIONS:

Séparez IIS et SQL Server sur deux boîtes différentes (de préférence) ou ajoutez de la mémoire supplémentaire à la boîte. Je pense que 3 à 4 Go devraient être un minimum.

Qu'en est-il de ces trucs EF étranges?

Le problème ici est qu’il est très probablement périphérique ou uniquement contributif à votre problème principal. N'oubliez pas que Profiler a résolu 90% de vos incidents. Il ne reste donc peut-être pas un problème différent, ou peut-être un des aggraveurs le plus extrême du problème. En raison de son comportement, j’imagine que le cache est en cours d’exécution ou que les processus du serveur d’applications sont gérés en arrière-plan.

Answer 2

Je voudrais comparer l'horodatage du délai d'attente avec le temps d'exécution de votre sauvegarde nocturne. S'ils coïncident, vous pouvez définir un flux RSS statique pour cette période.

Une autre chose à essayer (même si ce n'est pas exactement une réponse) est d'exécuter immédiatement sp_who lorsque vous obtenez une exception de délai d'expiration. Cela ne prendra pas tout (le processus incriminé pourrait être terminé au moment où vous l'exécuterez) mais vous aurez peut-être de la chance.

Vous pouvez également lancer SQL Profiler lorsque vous rentrez chez vous pour la nuit et commencer l'activité le lendemain matin si l'erreur se reproduit. Veillez simplement à ne pas l'exécuter à partir du serveur lui-même (je suis sûr qu'il vous le rappellera au démarrage).

MODIFIER: l'adresse de votre mise à jour.

EF met-il à jour / crée-t-il son cache? Cela pourrait expliquer l’abondance de requêtes en même temps et expliquer pourquoi aucune requête n’a eu de succès dans la base de données plus tard.

À part cela, il semble que vous ayez un heisenbug. La seule chose que je peux penser à ajouter, c’est beaucoup plus de journalisation (vers un fichier ou le journal des événements).

Answer 3

Ça sent une chose sale qui se déroule en même temps. Comme le dit RBarryYoung, des sauvegardes nocturnes ou autre chose Avez-vous un accès root au serveur? Pouvez-vous voir les crontabs?

Peut-il s'agir d'un plug-in d'indexation de texte intégral au-dessus du serveur SQL qui exécute ses procédures de réindexation peu de temps avant que vous ne rencontriez les problèmes?

Answer 4

Dans mon cas, lors de l'installation de sqlserver 2008 r2 sp3, le problème disparaissait.

Serveur: Windows 7 + SqlServer 2008 R2 (édition pour développeurs) client: Raspberrypi 3B +, Asp.net Core + EF Core