{"id":1380,"date":"2017-08-08T14:21:05","date_gmt":"2017-08-08T17:21:05","guid":{"rendered":"http:\/\/gianfratti.com\/?p=1380"},"modified":"2017-08-10T15:18:55","modified_gmt":"2017-08-10T18:18:55","slug":"identificando-a-causa-de-um-alto-e-crescente-consumo-de-memoria-em-producao","status":"publish","type":"post","link":"http:\/\/gianfratti.com\/index.php\/identificando-a-causa-de-um-alto-e-crescente-consumo-de-memoria-em-producao\/","title":{"rendered":"Identificando a causa de um alto e crescente consumo de mem\u00f3ria em produ\u00e7\u00e3o"},"content":{"rendered":"<p>Ol\u00e1 pessoal.<\/p>\n<p>Neste post descrevo uma forma de identificar a causa de um consumo crescente de mem\u00f3ria (poss\u00edvelmente <em>memory-leak<\/em>) em um aplicativo ASP.NET em produ\u00e7\u00e3o, sendo que n\u00e3o tenho acesso ao c\u00f3digo-fonte do aplicativo e t\u00e3o pouco contato com a equipe de desenvolvimento.<\/p>\n<p>Exemplifiquei aqui em ASP.NET, mas o procedimento pode ser para qualquer aplicativo .NET, seja ele, WinForms, WPF, Windows Services, etc.<!--more--><\/p>\n<h2>Cen\u00e1rio<\/h2>\n<p>O administrador da infraestrutura percebeu um alto e crescente consumo de mem\u00f3ria no processo w3wp.exe (IIS \u2013 servidor web), sendo que neste IIS est\u00e1 hospedado um aplicativo web ASP.NET (MVC 4).<\/p>\n<h2>Investiga\u00e7\u00e3o<\/h2>\n<h3>Passo 1 \u2013 Confirmar o alto consumo de mem\u00f3ria e o crescimento constante<\/h3>\n<p>Uma das formas f\u00e1ceis de confirmar de que est\u00e1 realmente havendo um crescente consumo de mem\u00f3ria \u00e9 utilizar os contadores de performance (perfmon.exe).<\/p>\n<p>Neste caso os seguintes contadores podem ser \u00fateis:<\/p>\n<ul>\n<li>Mem\u00f3ria do .NET CLR\n<ul>\n<li># Bytes in all Heaps para o processo w3wp.exe (IIS) \u2013 este contador ir\u00e1 nos mostrar quanto de mem\u00f3ria est\u00e1 sendo consumido ao longo do tempo e se \u00e9 crescente.<\/li>\n<\/ul>\n<\/li>\n<\/ul>\n<ul>\n<li>Aplicativos ASP.NET v4.0.30319 \u2013 \u00e9 interessante para confrontar a quantidade de mem\u00f3ria consumida em rela\u00e7\u00e3o a quantidade de usu\u00e1rios\/uso da aplica\u00e7\u00e3o\n<ul>\n<li>N\u00famero Total de Sess\u00f5es \u2013 em uma aplica\u00e7\u00e3o n\u00e3o stateless \u00e9 poss\u00edvel ter uma no\u00e7\u00e3o da quantidade de usu\u00e1rio que utilizaram a aplica\u00e7\u00e3o at\u00e9 o momento<\/li>\n<li>Sess\u00f5es ativas \u2013 em uma aplica\u00e7\u00e3o n\u00e3o stateless \u00e9 poss\u00edvel ter uma no\u00e7\u00e3o da quantidade de usu\u00e1rio que est\u00e3o utilizando neste momento<\/li>\n<li>Solicita\u00e7\u00f5es em Execu\u00e7\u00e3o \u2013 \u00e9 poss\u00edvel ter uma no\u00e7\u00e3o do quanto a aplica\u00e7\u00e3o est\u00e1 sendo utilizada (requisi\u00e7\u00f5es)<\/li>\n<li>Solicita\u00e7\u00f5es \/ segundo \u2013 \u00e9 poss\u00edvel ter uma no\u00e7\u00e3o de quantas requisi\u00e7\u00f5es est\u00e3o sendo processadas por segundo<\/li>\n<\/ul>\n<\/li>\n<\/ul>\n<p>Na primeira amostragem dos contadores (Figura 1), \u00e9 poss\u00edvel identificar que o w3wp.exe est\u00e1 consumindo cerca de 260MB de mem\u00f3ria com um baixo uso do aplicativo (apenas duas sess\u00f5es e requisi\u00e7\u00f5es por segundo quase zero). Ou seja, muita mem\u00f3ria mas pouca atividade dos usu\u00e1rios.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/eHgWBb5.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/eHgWBb5.png\" alt=\"\" width=\"593\" height=\"238\" \/><\/a><\/p>\n<p>Figura 1 \u2013 Primeira amostragem dos contadores<\/p>\n<p>Em uma segunda amostragem dos contadores (Figura 2), poucos minutos depois, \u00e9 poss\u00edvel identificar que o w3wp.exe teve um salto de consumo de mem\u00f3ria, indo a pr\u00f3ximo de 742MB de mem\u00f3ria mas ainda com baixo acesso ao servidor web (apenas tr\u00eas sess\u00f5es e n\u00famero de requisi\u00e7\u00f5es por segundo quase zero). Ou seja, incremento grande no consumo de mem\u00f3ria mas ainda pouco uso do aplicativo.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/ppXC3LK.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Segunda amostragem\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/ppXC3LK.png\" alt=\"\" width=\"552\" height=\"249\" \/><\/a><\/p>\n<p>Figura 2 \u2013 Segunda amostragem dos contadores<\/p>\n<p>A Figura 3 mostra o incremento de mem\u00f3ria em uma linha do tempo.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/PkvTcdH.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Amostragem ao longo do tempo\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/PkvTcdH.png\" alt=\"\" width=\"567\" height=\"438\" \/><\/a> Figura 3- Linha do tempo dos contadores<\/p>\n<p>A suspeita do administrador de infraestrutura est\u00e1 se confirmando, pois aparentemente o consumo de mem\u00f3ria apenas cresceu, sem ter um grande aumento no uso do aplicativo web.<br \/>\nO pr\u00f3ximo passo \u00e9 tentar descobrir o que est\u00e1 consumindo tanta mem\u00f3ria.<\/p>\n<h3>Passo 2 \u2013 Colher informa\u00e7\u00f5es do ambiente de produ\u00e7\u00e3o<\/h3>\n<p>H\u00e1 v\u00e1rias formas e fontes de informa\u00e7\u00f5es que nos podem ser \u00fateis em uma investiga\u00e7\u00e3o de problema em produ\u00e7\u00e3o. Neste caso de alto consumo de mem\u00f3ria um recurso muito \u00fatil \u00e9 o DUMP do processo w3wp.exe.<\/p>\n<p>Este dump \u00e9 uma esp\u00e9cie de fotografia do que o processo est\u00e1 fazendo neste momento e os recursos alocados por ele, por exemplo, quais objetos est\u00e3o em mem\u00f3ria neste instante, quais DLLs foram carregadas, etc.<\/p>\n<p>H\u00e1 formas variadas de gerar um dump, as mais comuns s\u00e3o atrav\u00e9s dos aplicativos adplus.exe, Debug Diag, Task Manager e WindDbg.<br \/>\nPara este artigo utilizei uma das formas mais simples de gerar um dump, usar o gerenciador de tarefas do Windows, por\u00e9m esta forma pode n\u00e3o servir para outras investiga\u00e7\u00f5es mais detalhadas.<\/p>\n<p>Selecionei o processo w3wp.exe e solicitei \u201cCriar arquivo de despejo\u201d, conforme mostrado na Figura 4.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/rUmnmH5.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Criar arquivo de despejo\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/rUmnmH5.png\" alt=\"\" width=\"405\" height=\"381\" \/><\/a> Figura 4 \u2013 Criar um arquivo dump b\u00e1sico<\/p>\n<p>O tempo para gerar o arquivo de despejo e o tamanho final do arquivo de dump varia conforme a quantidade de mem\u00f3ria alocada, podendo a ficar com alguns gigas de tamanha.<\/p>\n<p>Conclu\u00eddo a gera\u00e7\u00e3o do arquivo de despejo (dump), me \u00e9 informado onde est\u00e1 o arquivo criado (Figura 5).<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/FmBqOzX.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Path do arquivo de despejo\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/FmBqOzX.png\" alt=\"\" width=\"337\" height=\"169\" \/><\/a> Figura 5 \u2013 Caminho do arquivo dump<\/p>\n<p>Este arquivo \u00e9 o dump \u2013 fotografia do processo em um determinado momento. Analisando este arquivo poderemos descobrir a causa do alto consumo de mem\u00f3ria.<\/p>\n<h3>Passo 3 \u2013 Analisar o dump<\/h3>\n<p>Irei utilizar o <em>ntsd.exe (<\/em>utilit\u00e1rio da Microsoft dispon\u00edvel no Windows SDK &#8211; <a title=\"Windows SDK Download\" href=\"http:\/\/msdn.microsoft.com\/en-us\/library\/windows\/desktop\/hh852363.aspx\" target=\"_blank\" rel=\"noopener\">download<\/a>) dispon\u00edvel na pasta C:\\Program Files (x86)\\Windows Kits\\8.0\\Debuggers\\x64.<\/p>\n<p>Usando o PowerShell aciono o <em>ntsd.exe<\/em> informando que quero analisar um arquivo de dump (par\u00e2metro \u2013z) e o local do arquivo de dump.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/xPoKCnk.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Acionamento do debugger ntsd.exe\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/xPoKCnk.png\" alt=\"\" width=\"667\" height=\"105\" \/><\/a><\/p>\n<p>Figura 6 \u2013 Iniciar o debugger ntsd.exe para an\u00e1lise do dump<\/p>\n<p>Ent\u00e3o \u00e9 aberto uma tela do aplicativo console ntsd.exe.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/x3ir2sX.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"ntsd.exe em execu\u00e7\u00e3o\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/x3ir2sX.png\" alt=\"\" width=\"542\" height=\"274\" \/><\/a><\/p>\n<p>Figura 7 \u2013 ntsd.exe em execu\u00e7\u00e3o<\/p>\n<p>Antes de come\u00e7ar a analisar o dump, \u00e9 necess\u00e1rio fazer alguns ajustes para informar ao ntsd.exe que ele deve carregar algumas informa\u00e7\u00f5es para analisar um aplicativo .NET.<\/p>\n<p>Ajustar o s\u00edmbolos de depura\u00e7\u00e3o com .symfix e .reload<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/GUfaJg9.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Corre\u00e7\u00e3o dos s\u00edmbolos para depura\u00e7\u00e3o\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/GUfaJg9.png\" alt=\"\" width=\"542\" height=\"207\" \/><\/a><\/p>\n<p>Figura 8 \u2013 Corre\u00e7\u00e3o para os s\u00edmbolos de depura\u00e7\u00e3o<\/p>\n<p>Carregar as extens\u00f5es para an\u00e1lise de aplicativos .NET: sos.dll e clr.dll<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/tquZuaw.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Carga do sos.dll e clr.dll\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/tquZuaw.png\" alt=\"\" width=\"542\" height=\"207\" \/><\/a><\/p>\n<p>Figura 9 \u2013 Carregando o sos.dll e clr.dll<\/p>\n<p>Tudo preparado, hora de come\u00e7ar a investigar.<\/p>\n<p>Uma primeira a\u00e7\u00e3o \u00e9 dar uma olhada na <em>heap<\/em> de mem\u00f3ria do aplicativo para ver se identificamos algo suspeito.<\/p>\n<p>Para isso utilizo o comando: <em>!DumpHeap -stat, <\/em>que fornece estat\u00edsticas dos objetos alocados pelo aplicativo, ordenados pelo consumo de mem\u00f3ria.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/IRqXJaN.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Estat\u00edsticas dos objetos alocados em mem\u00f3ria\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/IRqXJaN.png\" alt=\"\" width=\"631\" height=\"269\" \/><\/a> Figura 10 \u2013 Estat\u00edsticas da <em>heap<\/em><\/p>\n<p>J\u00e1 podemos notar que dos 260MB ocupados na primeira amostragem (momento que foi tirado o dump), h\u00e1 482 objetos do tipo array de bytes ocupando 168MB, representando cerca de 64% de toda a mem\u00f3ria ocupada.<br \/>\nBastante suspeito, ent\u00e3o vamos dar uma olhada mais a fundo nisso, listando detalhes de todos os 482 objetos array de bytes, para depois investigar um deles aleatoriamente.<\/p>\n<p>Para isso, executo o comando \u201c<em>!DumpHeap -mt 000007f92c88f490<\/em>\u201c, onde o endere\u00e7o informado \u00e9 o Method Table (-mt) do System.Byte[] mostrado na figura anterior.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/SL1iImn.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Lista de objetos\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/SL1iImn.png\" alt=\"\" width=\"631\" height=\"346\" \/><\/a> Figura 11 \u2013 Listar os 482 objetos do tipo System.Byte[]\n<p>Dos 482 objetos listados, escolho um quase aleatoriamente, digo quase pois opto por um que est\u00e1 com uma quantidade maior de mem\u00f3ria (\u00faltima coluna exibida). Escolhido qual objeto investigar, utilizo o comando \u201c<em>!do endere\u00e7o<\/em>\u201d, por exemplo, escolhi o \u00faltimo listado (<em>!do 000000ee92121090<\/em>) pois ocupa 10MB.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/rLiBc96.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"DumpObject\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/rLiBc96.png\" alt=\"\" width=\"631\" height=\"298\" \/><\/a><\/p>\n<p>Figura 12 \u2013 Detalhes de um objeto espec\u00edfico<\/p>\n<p>Nesta imagem podemos perceber que \u00e9 um objeto Array de uma dimens\u00e3o (Rank 1) com 10MB de tamanho (elementos).<\/p>\n<p>Se o conte\u00fado fosse string, poder\u00edamos saber o que tem nele na propriedade Content, mas como \u00e9 bytes, preciso investigar quem \u00e9 que est\u00e1 usando este objeto, quem \u00e9 o \u201croot\u201d do objeto.<\/p>\n<p>Para isso, utilizo o comando \u201c<em>!gcroot endere\u00e7o<\/em>\u201d, por exemplo, <em>!gcroot 000000ee92121090<\/em>.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/cBjZQ7M.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"Root de um objeto\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/cBjZQ7M.png\" alt=\"\" width=\"631\" height=\"451\" \/><\/a> Figura 13 \u2013 GCRoot do objeto investigado<\/p>\n<p>Eis que a Figura 13 nos d\u00e1 algumas informa\u00e7\u00f5es interessantes, sendo elas:<\/p>\n<ol>\n<li>\u201c<em>Found 1 unique roots<\/em>\u201d \u2013 s\u00f3 h\u00e1 uma refer\u00eancia para este objeto array.<\/li>\n<li>\u201c<em>MvcApplication7.MyObject<\/em>\u201d \u00e9 quem est\u00e1 apontando para este objeto. Com esse nome, provavelmente \u00e9 um c\u00f3digo do fornecedor do aplicativo em execu\u00e7\u00e3o. Ao acionar a equipe de desenvolvimento, \u00e9 poss\u00edvel dizer para eles que a classe MyObject est\u00e1 alocando um array de bytes de 10MB e aparentemente causando o alto consumo de mem\u00f3ria.<\/li>\n<li>\u201c<em>System.Web.SessionState.SessionStateItemCollection<\/em>\u201d \u2013 indicador que o MyObject est\u00e1 sendo mantido na sess\u00e3o do usu\u00e1rio do ASP.NET, ou seja, aparentemente ficar\u00e1 com a mem\u00f3ria alocada durante toda a vida \u00fatil da sess\u00e3o, que por padr\u00e3o \u00e9 20 minutos.<\/li>\n<li>\u201c<em>System.Web.SessionState.InProcSessionState<\/em>\u201d \u2013 indica que a sess\u00e3o do ASP.NET est\u00e1 InProc, ou seja, sendo mantida no pr\u00f3prio processo w3wp.exe, confirmando que o armazenamento do MyObject na sess\u00e3o ir\u00e1 impactar diretamente no consumo de mem\u00f3ria do processo w3wp.exe.<\/li>\n<\/ol>\n<p>Feito! Conseguimos identificar de forma espec\u00edfica uma classe que \u00e9 a poss\u00edvel causadora do problema, isso sem ter acesso ao c\u00f3digo fonte do aplicativo.<br \/>\nAgora ent\u00e3o bastaria passar essas informa\u00e7\u00f5es para a equipe de desenvolvimento do aplicativo para que eles avaliem se \u00e9 um bug ou uma caracter\u00edstica do aplicativo.<\/p>\n<p>A t\u00edtulo de curiosidade, a imagem abaixo representa o \u201cculpado\u201d pelo alto consumo de mem\u00f3ria no c\u00f3digo-fonte do aplicativo analisado em produ\u00e7\u00e3o.<\/p>\n<p><a href=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/52bhoxX.png\"><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter\" title=\"C\u00f3digo fonte do aplicativo em produ\u00e7\u00e3o\" src=\"http:\/\/gianfratti.com\/wp-content\/uploads\/2017\/08\/52bhoxX.png\" alt=\"\" width=\"659\" height=\"410\" \/><\/a><\/p>\n<p>Figura 14 \u2013 C\u00f3digo fonte do aplicativo executado em produ\u00e7\u00e3o<\/p>\n<p><em>Observa\u00e7\u00e3o: este c\u00f3digo n\u00e3o \u00e9 de um aplicativo real, foi constru\u00eddo para exemplificar o problema de mem\u00f3ria.<\/em><\/p>\n<p>Fonte: <a href=\"http:\/\/www.rafaelleonhardt.com.br\/2013\/07\/20\/asp-net-troubleshooting-identificando-a-causa-de-um-alto-e-crescente-consumo-de-memoria-em-producao\/\" target=\"_blank\" rel=\"noopener\">Clique aqui<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"<p>Ol\u00e1 pessoal. Neste post descrevo uma forma de identificar a causa de um consumo crescente de mem\u00f3ria (poss\u00edvelmente memory-leak) em um aplicativo ASP.NET em produ\u00e7\u00e3o, sendo que n\u00e3o tenho acesso ao c\u00f3digo-fonte do aplicativo e t\u00e3o pouco contato com a equipe de desenvolvimento. Exemplifiquei aqui em ASP.NET, mas o procedimento pode ser para qualquer aplicativo <span class=\"ellipsis\">&hellip;<\/span> <span class=\"more-link-wrap\"><a href=\"http:\/\/gianfratti.com\/index.php\/identificando-a-causa-de-um-alto-e-crescente-consumo-de-memoria-em-producao\/\" class=\"more-link\"><span>Read More &rarr;<\/span><\/a><\/span><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_exactmetrics_skip_tracking":false,"_exactmetrics_sitenote_active":false,"_exactmetrics_sitenote_note":"","_exactmetrics_sitenote_category":0,"_jetpack_memberships_contains_paid_content":false,"footnotes":""},"categories":[201,200],"tags":[],"class_list":["post-1380","post","type-post","status-publish","format-standard","hentry","category-net","category-troubleshooting"],"jetpack_featured_media_url":"","jetpack_sharing_enabled":true,"_links":{"self":[{"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/posts\/1380","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/comments?post=1380"}],"version-history":[{"count":1,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/posts\/1380\/revisions"}],"predecessor-version":[{"id":1395,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/posts\/1380\/revisions\/1395"}],"wp:attachment":[{"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/media?parent=1380"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/categories?post=1380"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/gianfratti.com\/index.php\/wp-json\/wp\/v2\/tags?post=1380"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}