Ajuda solução de problemas SqlException: tempo limite expirou em conexão, em uma situação sem carga

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

Pergunta

Eu tenho um servidor que hospeda um site da mina que tem quase zero tráfego.
Algumas pessoas (<20) entrar no site a cada dia, e alguns leitores de RSS está inscrito para alguns feeds que colocamos para fora.

Quase todas as noites, um leitor de RSS vai bater-nos no meio da noite e obter uma exceção que o site não pode se conectar ao SQL Server por causa de um tempo limite na conexão. Os detalhes são extremamente estranho, por isso estou procurando alguma ajuda sobre o que poderia ser o problema, já que eu não sei onde começar a procurar mais.

Estamos usando ASP.Net MVC, Entity Framework e do SQL Server 2008 sobre o Windows Server 2008. A máquina é uma caixa dedicada chegamos de um provedor não exatamente alto nível, então as coisas podem ser configurados não-ideal, ou quem sabe mais o quê.
A caixa também é muito pequena, e tem apenas 1 GB de RAM, mas deve ter o tipo de carga que temos para agora ...

Eu estou copiando a pilha de chamadas completa abaixo, mas em primeiro lugar, algumas das coisas que nós sabemos:

  • O erro sempre acontece quando o iTunes está consultando o nosso site. Eu acredito que este deve ter nada a ver com nada, mas a verdade é que só obtê-lo a partir do iTunes. Meu melhor palpite é que isso acontece porque apenas iTunes consultas nós naquele tempo da noite, quando ninguém mais está nos atingindo.
  • Uma das nossas teorias é que o SQL Server e IIS estão lutando para a memória, e um deles está sendo paginada para disco fora de não ser usado, e quando alguém "acorda-lo", que leva muito tempo para ler tudo de trás do disco para a memória. Isto é algo que poderia potencialmente acontecer? (Eu sou o tipo de descartar isso, pois soa como um problema de design no SQL Server se fosse possível)
  • Eu também pensei sobre a possibilidade de que estamos vazando conexões, já que não pode ser a eliminação de entidades EF de forma adequada ( ver a minha pergunta aqui ). Esta é a única coisa que eu poderia encontrar por Googling o problema. Eu estou descartando isso dada a extremamente baixa carga que temos.
  • Isto sempre acontece durante a noite, por isso é muito provável que algo relacionado ao fato de que nada aconteceu por algum tempo. Por exemplo, eu tenho certeza que quando esses pedidos atingido, o processo do servidor web foi reciclado e está começando-se / re-JITting tudo. A re-JITting não explica o tempo limite SQL, no entanto.

UPDATE: Nós anexado um profiler como sugerido, e demorou um bom tempo antes que nós tivemos uma nova exceção. Este é o novo material que nós sabemos:

  • Tendo o profiler anexado enormemente reduziu o número de erros que temos. De fato, depois normalmente recebendo vários por dia, tivemos de esperar por 3 ou 4 dias para que isso aconteça uma vez. Assim que parou o profiler, ele voltou para a freqüência de erro normal (ou pior). Assim, o profiler tem alguns efeito que os couros este problema até certo ponto, mas não completamente.
  • Olhando para o rastreamento do profiler ao lado do IIS registo de pedidos, há uma espera 1-1 correspondência entre pedidos e consultas. No entanto, de vez em quando, eu vejo um monte de consultas que está sendo executado que não têm correllation em tudo com o log de IIS. Na verdade, mesmo antes do bug real foi registrado, eu tenho 750 consultas em um período de 3 minutos, , todos os quais foram completamente alheios ao logs do IIS. O olhar texto de consulta como o tipo de porcaria ilegível que EF gera, e eles não são todos iguais, e todos eles são parecidos com as consultas provenientes do site: Same ApplicationName, usuário, etc. Para dar uma idéia de como isso ridículo é, o site tem cerca de 370 IIS pedidos que chegam ao DB, no curso de 2 dias
  • Estas consultas inexplicáveis ??não vêm da mesma ClientProcessID como os sites anteriores, embora eles ainda podem ter vindo do site, se o processo got reciclada no mesmo período. Havia quase uma hora de nenhuma atividade entre a última explicou consulta, eo primeiro inexplicável.
  • Uma dessas longas faixas de consultas que eu não sei de onde vieram veio logo antes do erro que eu tenho registrado, então eu acredito que esta é a pista que deve seguir.
  • Como eu esperava inicialmente, quando a consulta que jogou o erro foi executado, ele veio de uma ClientProcessID diferente do que o anterior, (8 minutos mais tarde do que o inexplicável anterior, e quase exatamente uma hora mais tarde do que o IIS anterior ). Isso significa, para mim, que o processo de trabalho de fato tinha começado reciclado.
  • Este é algo que eu absolutamente não entendem. O registo mostra o IIS que um minuto antes de os pedidos de erro, 4 foram perfeitamente servidos, embora as consultas para aqueles não aparecem no rastreamento de todo. De fato, após os 4 que correu bem, tive 4 exceções lançadas em rápida sucessão, os 4 também não aparecem no rastreamento (que faz sentido uma vez que se houvesse um tempo limite em relação a consulta nunca deveria ter começado executado, mas eu não vejo as tentativas de conexões no rastreamento quer)

Então, em suma, estou completamente à nora sobre isso. Não consigo encontrar uma razão para as centenas de consultas que são executados em rápida sucessão, mas eu acredito que aqueles deve ter algo a ver com o problema.
Eu também não sei como diagnosticar os problemas de conexão ...
Ou como o rastreamento do Profiler pode estar faltando algumas consultas que de acordo com o IIS passou por bem ...

Todas as idéias?

Esta é a informação exceção: 

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)

Todas as ideias serão enormemente apreciado.

Foi útil?

Solução

Memória Insuficiente

Isto é muito provavelmente um problema de memória, talvez agravada ou desencadeada por outras coisas, mas ainda inerentemente um problema de memória. há duas outras (menos provável) possibilidades, que você deve verificar e eliminar primeiro (porque é fácil fazê-lo):

fácil de verificar Possibilidades:

  1. Você pode ter "Auto Close" ativado: Auto Close pode ter exatamente esse comportamento, no entanto, é raro para que ele seja ligado. Para verificar isso, no SSMS botão direito do mouse no banco de dados do aplicativo, selecione "Propriedades" e selecione o painel "Opções". Olhe para a entrada "Auto Close" e certifique-se de que ela é definida como False. Verifique tempdb também.

  2. SQL Agent Jobs pode estar causando isso: Verifique History Log do Agente para ver se havia algum emprego consistentemente em execução durante os eventos. Lembre-se de verificar os trabalhos de manutenção também, como coisas como Recriando índices são freqüentemente citados como problemas de desempenho, enquanto eles estão em execução. Estes são candidatos improváveis ??agora, só porque eles normalmente não seriam afetados pela Profiler.

Por que se parece com um problema de memória:

Se aqueles não mostram nada, então você deve verificar se há problemas de memória. I Memória suspeita como a causa no seu caso porque:

  • Você tem 1 GB de memória: Embora isso seja tecnicamente acima da mínima para SQL Server, é muito abaixo do recomendado para SQL Server, e bem abaixo do que na minha experiência é aceitável para a produção, mesmo para um levemente servidor carregado.

  • Você está executando o IIS e SQL Server na mesma caixa: Isso não é recomendado, por si só, em grande parte por causa da contenção de memória que os resultados, mas com apenas 1 GB de memória resulta em IIS, o aplicativo, SQL Server, o sistema operacional e quaisquer outras tarefas e / ou manutenção de toda a luta para muito pouca memória. A forma como o Windows gerencia este é para dar memória para os processos ativos, levando-a agressivamente longe dos processos não-ativos. Pode demorar muitos segundos ou mesmo minutos para um processo grande como SQL Server para voltar o suficiente de sua memória para ser capaz de atender completamente um pedido por esta situação.

  • Profiler fez 90% do problema desaparecer: Este é um grande indício de que a memória é provável que o problema, porque normalmente, coisas como Profiler têm exatamente esse efeito sobre este problema em particular: a tarefa Profiler mantém o SQL Server apenas um pouco mordeu todos os ativos do tempo. Frequentemente, este é apenas bastante atividade, quer mantê-lo fora da lista "tesouro" do OS, ou pelo menos reduz de impacto pouco.

Como verificar a memória como o culpado:

  1. Desligar o Profiler:. Sua ter um efeito Heisenberg sobre o problema, então você tem que desligá-lo ou você não será capaz de ver o problema de forma confiável

  2. Executar um Monitor do sistema (Perfmon.exe) de outra caixa, que se conecta remotamente ao serviço de coleta perfomrance na caixa que o seu SQL Server e IIS está sendo executado. você pode mais facilmente fazer isso, primeiro removendo os três estatísticas padrão (eles são apenas local), e em seguida, adicione nas estatísticas necessários (abaixo), mas certifique-se de alterar o nome do computador no primeiro drop-down para conectar ao seu SQL caixa.

  3. Enviar os dados coletados em um arquivo, criando uma "Counter Log" na perfmon. Se você não estiver familiarizado com este, em seguida, a melhor coisa a fazer é, provavelmente, para coletar os dados para um guia ou uma vírgula separados arquivo que você pode abrir com o Excel para analisar.

  4. Configurar o perfmon para recolher para um arquivo e adicionar os seguintes contadores para isso:

    - Processor \% Processor Time [Total]

    - PhysicalDisk \% Tempo ocioso [ para cada disco ]

    - PhysicalDisk \ AVG. Disk Queue Length [ para cada disco ]

    - Memória \ Páginas / s

    - Memória \ Leituras de Página / s

    - Memória \ MBytes disponíveis

    - Interface de Rede \ Bytes Total / seg [ para cada interface em uso ]

    - Process \% Processor Time [ ver abaixo ]

    - Process \ falhas de página / seg [ ver abaixo ]

    - Process \ Conjunto de trabalho [ ver abaixo ]

  5. Para os contadores de processo (acima) que pretende incluir o processo sqlserver.exe, qualquer IIS processos e quaisquer processos de aplicação estável. Note que isto só irá funcionar para os processos "estáveis". Processos que estão continuamente a ser re-criados conforme a necessidade, não podem ser capturadas dessa maneira porque não há nenhuma maneira de especificar los antes que eles existem.

  6. Executar esta coleção para um arquivo durante o tempo em que o problema mais freqüentemente acontece. Defina o intervalo de coleta para algo perto de 10-15 segundos. (Este recolhe muitos dados, mas você vai precisar desta resolução para escolher os eventos separados).

  7. Depois de ter um ou mais incidentes, pare a coleta e em seguida, abra o arquivo de dados colleced com Excel. Você provavelmente vai ter que reformatar a coluna timestamp para ser utilmente visível e mostrar horas minutos e segundos. Use seu IIS log para encontrar o momento exato dos incidentes, em seguida, olhar para os dados Perfmon para ver o que estava acontecendo antes e depois do incidente. Em particular, você quer ver se o seu conjunto de trabalho era pequena antes e era grande depois, com um monte de página falha no meio. Esse é o sinal mais claro deste problema.

SOLUÇÕES:

De qualquer separada IIS e SQL Server em duas caixas diferentes (de preferência) ou então adicionar mais memória para a caixa. Gostaria de pensar que 3-4 GB deve ser um mínimo.

que sobre esse estranho EF material?

O problema aqui é que o mais provável é periférico ou apenas contributivo para o seu problema principal. Lembre-se que Profiler feita de 90% de seus incidentes ir embora, então o que resta, pode ser um problema diferente, ou pode ser apenas o mais extremo aggravator do problema. Por causa de seu comportamento eu acho que ele é ou ciclismo seu cache ou há algum outro fundo manutenção dos processos de servidor de aplicativos.

Outras dicas

Gostaria de comparar o timestamp do tempo limite com o tempo de execução do seu backup noturno. Se eles coincidem, você pode definir seu feed RSS para ser estático para a época.

Outra coisa a tentar (mesmo que ele não é exatamente uma resposta) é executar imediatamente sp_who quando você recebe uma exceção de tempo limite. Ele não vai pegar tudo (o processo ofensivo poderia ser feito pelo tempo que você executar este), mas você pode ter sorte.

Você também pode disparar o SQL Profiler quando você ir para casa para a noite e passo através da atividade na manhã seguinte se você ver o erro novamente. Apenas certifique-se de não executá-lo a partir do próprio servidor (eu tenho certeza que você lembra disso quando ele começa).

EDIT:. Dirigindo sua atualização

é EF atualização / criação de seu cache? Ele poderia explicar a abundância de consultas ao mesmo tempo e por isso há consultas tiveram acessos de banco de dados mais tarde.

Além disso, parece que você tem uma heisenbug. A única coisa que posso pensar para você adicionar é muito mais log (para um arquivo ou registo de eventos).

Tem cheiro uma coisa cronned que é executado ao mesmo tempo. Como diz RBarryYoung .. alguns backup noturno ou poderia ser outra coisa Você tem acesso root ao servidor? você pode ver os crontabs?

Poderia ser algum plugin indexação de texto completo em cima do servidor SQL que executa seus procedimentos reindexação perto do tempo que você está enfrentando as questões?

No meu caso, quando eu instalado sqlserver 2008 R2 SP3, o problema desaparece.

Servidor: Windows 7 + SqlServer 2008 R2 (Developer Edition) cliente: Raspberry Pi 3B +, Asp.net Núcleo + EF Núcleo

Licenciado em: CC-BY-SA com atribuição
Não afiliado a StackOverflow
scroll top