Identificando Problemas – Memória no AdvPL – Parte 01

Introdução

Normalmente identificar um problema em um ambiente de produção é uma mistura de talentos. Você deve ser um pouco garimpeiro, um pouco psiquiatra, um pouco detetive … Um dos primeiros posts a respeito de “problemas” está no link https://siga0984.wordpress.com/2014/12/14/pense-fora-da-caixa-e-resolva-problemas/ . No post de hoje, vamos arranhar a tampa da caixa de Pandora …

Problemas

“Um problema é uma dificuldade na obtenção de um determinado objectivo. Em certos contextos pode ter um significado especial” — Wikipédia

No contexto da tecnologia da informação, um problema é um nome bonito e simples para ilustrar que “algo não está funcionando como deveria funcionar”. A questão está em resolver esse “algo errado”, seguido das duas perguntas mais intrigantes da humanidade: “POR QUÊ ?” e “COMO FAZ PRA RESOLVER”.

O quê, onde, (desde) quando e como

São as quatro perguntas iniciais de qualquer problema. Primeiro, o que foi identificado ou nomeado como sendo um problema. A resposta desta pergunta também ajuda a identificar a criticidade do problema. Normalmente qualquer departamento de suporte está sujeito a receber uma ligação com um cliente ou analista de campo esbaforido, que logo diz o seguinte: “PelamordeDeus, o sistema caiu…”.

Um problema pode ser desde uma diferença de valores mostrados em dois relatórios, que em tese deveriam chegar a um mesmo número, uma impossibilidade de uso de uma determinada rotina devido a uma validação de dados que não está permitindo a continuidade do processo, uma finalização do programa ou rotina com uma mensagem de erro seguido do fechamento da aplicação de interface, uma etapa de processo que ao ser acionada “trava” a aplicação, ou um determinado processo (ou o sistema inteiro) demora muito para ser concluído ( lentidão isolada ou generalizada), enfim, tudo é “problema”.

Normalmente a criticidade de um problema não está ligado tecnicamente a dificuldade de resolver ou entender o problema, mas sim no que isso causa para o cliente. Não conseguir imprimir uma Fatura ou Nota de Saída de mercadorias, quando o cliente está com um caminhão de mercadorias fechando a saída da empresa esperando a nota sair, para o cliente isso é um problema de criticidade máxima.

Os demais detalhes (onde , quando e como) são muito importantes, pois vão dar uma idéia de localização do problema, (desde) quando ele passou a acontecer, e “como” ele acontece — ou melhor, o que precisa ser feito e de que forma para que o “problema” se manifeste. O “como” é a receita de bolo para fazer o problema acontecer. Você precisa saber de todos os ingredientes, a ordem que foram colocados na panela, se o fogo estava ligado antes dos ingredientes serem colocados lá, e por aí vai.

E, uma observação muito bem lembrada pelo meu amigo Alan Cândido… Normalmente o quando (desde quando), deve vir junto com a pergunta: Qual foi a última vez que funcionou, e o que aconteceu no ambiente entre a última vez que funcionou e foi percebido que a rotina / programa / sistema apresentou o problema? Houve alteração de customização atualização de ambiente, binário, RPO, update do Windows, deploy de serviço, alteração de parametrização ou configuração, etc…?  Todos os dados são relevantes, nem sempre eles parecem estar conectados, mas são relevantes.

O Contorno

Muitas vezes precisamos arrumar um contorno para o problema para depois resolvê-lo. A nota fiscal não está saindo na Impressora 01 ? Tente na impressora 02. A rotina não começa a imprimir pois acontece um erro de execução ? Começou a acontecer ontem, depois de uma atualização de sistema ? Verifique se dá pra voltar a versão anterior do ambiente (caso exista). Existem problemas que não tem contorno, ou que o contorno pode causar mais problemas. É necessário ser criterioso na avaliação e para propor uma alternativa viável.

Descobrindo a causa

Bem, para cada tipo de problema, existe um roteiro para descobrir a causa. Alguns problemas não tem causa aparente, então tudo em volta do problema deve ser verificado. Esta investigação e o registro dela vão ajudar os responsáveis por arrumar o problema a entender tudo o que já foi verificado e qual é o cenário onde o problema se manifesta.

Partindo para a solução

Uma vez que o problema e sua causa foi entendida, a solução do problema pode ser um procedimento, executado pelo cliente ou por um analista, ou DBA, ou uma atualização de um programa, ou de um executável ou DLL, da mesma forma que um problema é “algo”, a solução é “fazer alguma coisa” — o leque de opções é extremamente amplo. Um ponto importante ao fornecer uma solução é sinalizar ao cliente se isso realmente vai ( ou deveria resolver o problema ), ou se é uma ação sobre uma provável causa. Normalmente depois da terceira vez que você pede para o cliente fazer mais alguma coisa no ambiente dando a entender que aquilo é a solução, e a ação proposta não resolve, fica muito mais difícil dar suporte a um cliente que não acredita mais no suporte.

Entrando no AdvPL

Até agora, todos os parágrafos anteriores não traz nenhuma novidade, é o “Be-a-bá” do Analista de Suporte. Agora, vamos entrar em uma análise de ocorrência que costuma deixar todos de cabelo em pé … “Consumo de memória”, no contexto de uma aplicação AdvPL. Vamos “fatiar” esse assunto, para ser possível devorá-lo sem se engasgar.

Definição de Consumo de Memória

Quando usamos a expressão “consumo de memória”, entendemos que isto significa a quantidade total de memória RAM (também conhecida por memória volátil) alocada por uma aplicação em execução pelo sistema operacional em um equipamento, usada internamente para armazenar o próprio programa em execução, juntamente com os dados que são ou podem ser carregados para a memória para serem mostrados na interface, gravados ou lidos de uma unidade de disco ou de um banco de dados, e assim por diante.

Todo e qualquer programa apresenta um consumo de memória de acordo com “o que” o programa está carregando na memória. Um programa AdvPL pode criar um array e ler registros de uma Query do banco de dados, e isso vai consumir memória proporcionalmente em razão da quantidade de linhas e colunas populadas desse Array.

Memória total do equipamento

Em um computador, temos uma quantidade limitada de memória RAM. Um equipamento Desktop pode vir com 4 GB (gigabytes) de memória, ou mais. Equipamentos servidores, dependendo do porte do servidor, podem ter de 32 GB a 128 GB de memória. Este recurso será dividido entre todos os programas e serviços que estão sendo executados no equipamento, inclusive o próprio sistema operacional do equipamento.

Tendo essa perspectiva em vista, antes de mais nada é necessário saber quanto de memória a versão do sistema operacional do equipamento precisa para operar com “folga”. Caso a soma dos aplicativos carregados na memória mais o sistema operacional cheguem perto do limite físico de memória, o sistema operacional começa a transferir áreas da memória para o disco rígido (HD) do equipamento, e isso definitivamente têm um impacto muito grande no desempenho das aplicações em execução.

Memória por aplicativo

Cada aplicativo pode possuir uma característica diferenciada de consumo de memória. SGBDs normalmente consomem o tamanho necessário ou disponível (sob demanda ou pré-reservado) para manter os dados e índices mais acessados espelhados em memória, para proporcionar maior desempenho — é mais rápido buscar uma informação na memória do que no disco. Normalmente você configura um limite de memória que o SGBD pode usar, para que ele não “morda” toda a memória do servidor. Uma vez que este limite seja atingido, o SGBD “se vira” para tirar do cache as informações menos acessadas.

Quando vamos colocar mais aplicativos para serem executados no mesmo equipamento, precisamos tomar o cuidado de não deixar eles tomarem posse de mais memória do que a disponível para uso, senão já sabemos o que acontece …

AdvPL e Consumo sob demanda

Como acabamos de ver, um SGBD normalmente consome a memória montando caches de dados e índices conforme a base de dados é acessada mediante solicitações de uma aplicação. Porém, uma vez definido ou atingido um limite, o SGBD pode manter na memória os caches dos dados mais utilizados, e descartar os caches pouco acessados. Conforme a aplicação vai solicitando informações, o SGBD “se vira” para gerenciar os caches da melhor forma possível.

Quando temos uma aplicação que consome memória para um contexto de execução, normalmente tudo o que está sendo executado precisa estar na memória RAM, por questões de desempenho. O servidor de aplicação AdvPL – Totvs Application Server – consome memória sob demanda, para cada contexto de execução. Uma nova conexão vinda de um SmartClient ou um novo JOB iniciado no AdvPL (processo sem interface) vão consumir memória para carregar o(s) programa(s) do repositório de objetos (RPO), e memória para armazenar os conteúdos das variáveis do programa alimentadas durante a sua execução ( Instâncias de classes, strings, etc). Por ser uma aplicação multi-thread, isto é, com múltiplos processos internos, cada thread possui uma reserva mínima de memória feita pelo sistema operacional, mas toda a memória alocada por todos os processos são vistas como uma coisa só para o sistema operacional do equipamento. Tudo fica “em nome” do executável.

Quando uma aplicação qualquer, como por exemplo um SmartClient, realiza a carga de uma DLL para integração com um periférico ou serviço, caso os programas e funções da DLL precisem de memória, eles vão pedir para o sistema operacional, porém esta memória vai ser contabilizada para o executável do SmartClient, que fez a carga da DLL. A mesma coisa acontece para o DBAccess (Gateway de acesso a bancos de dados relacionais) e o TOTVS Application Server. Cada driver ( DLL/SO) de acesso a dados que consumir memória vai usar a área de endereçamento do executável.

Consumo de memória por Thread

O TOTVS Application Server possui um mecanismo de monitoramento de memória por thread, que pode ser habilitado utilizando a chave DebugThreadUsedMemory=1 na seção [GENERAL] do arquivo de configuração (appserver.ini). — Vide TDN no link http://tdn.totvs.com/display/tec/DebugThreadUsedMemory. Com este recurso habilitado, o TOTVS Application Server passa a registrar as alocações e liberações de memória de cada processo (thread) em execução, e mostra essa informação em uma coluna adicional na interface de monitoramento (TOTVS Monitor e/ou TDS Server Monitor).

Cada processo ou thread AdvPL em execução mantém na memória os fontes das funções chamadas durante a execução do programa, e como os programas podem alimentar variáveis de memória de tamanho dinâmico, alguns programas podem apresentar um consumo de memória maior ou menor em relação a outros. Inclusive, como o primeiro programa a ser executado provavelmente fará a carga das DLLS de acesso ao c-Tree e ao DBAccess, e mantém estas DLLs alocadas até o serviço do TOTVS Application Server ser finalizado, a primeira thread que entra no sistema para executar código AdvPL pode passar uma falsa sensação de consumo mais elevado que as demais.

Onde um programa aloca a memória ?

Além das variáveis de memória, criadas pelo programa e que podem ser alimentadas dinamicamente, contendo strings, objetos, arrays e afins, existem outros recursos que também consomem memória. Cada tabela aberta e em uso pelo sistema consome alguns KB de memória. Este consumo não é proporcional a quantidade de registros da tabela, mas é proporcional a quantidade de colunas, e a soma do tamanho de todas as colunas ( tamanho do registro). Cada aplicação de interface AdvPL, acessada pelo SmartClient, aloca e mantém na memória uma instância de cada classe de objeto de interface criado pelo programa em execução até que a janela ou container destes componentes seja fechado.

Logo, uma janela de diálogo de interface com mais componentes vai consumir mais memória do que um programa com menos componentes. Um processo com mais tabelas abertas tende a consumir mais do que um processo com menos tabelas e queries mantidas abertas.

Processo dedicado de monitoramento de memória

A partir do TOTVS Application Server, Build 7.00.100812P, foi introduzido no servidor de aplicação um processo interno dedicado ao monitoramento de memória. Vide TDN no link http://tdn.totvs.com/pages/viewpage.action?pageId=6065765. Com este processo “de olho” no consumo de memória do servidor AdvPL, caso a memória endereçada pelo serviço ultrapasse um limite seguro, automaticamente as novas conexões e nocas inicializações de Jobs são desabilitados. Em um ambiente de balanceamento de carga, o servidor “Master” ou “Balance” identifica este cenário, e não redireciona novas conexões para este serviço.

Para facilitar a identificação de onde a memória está sendo utilizada por cada programa, e inclusive para evitar que um programa consuma memória acima de um determinado limite, foram criadas configurações adicionais para monitoramento de memória, onde é possível definir por thread um limite de advertência e uum limite máximo de consumo. Neste caso, uma vez que o limite seja atingido, aquele processo é derrubado do sistema. Os detalhes desta implementação estão na TDN, no link http://tdn.totvs.com/pages/viewpage.action?pageId=6065765

Adicionalmente, caso seja definido um limite de advertência de consumo por processo, quando este limite for atingido, será gerado um error.log de advertência, onde são informados no stack de execução quais variáveis estão na memória e qual a estimativa de consumo para cada uma.

O que é “LEAK” de memória ?

O termo “memory leak”, ou ‘vazamento de memória’ é aplicado a um processo, que durante a sua execução realiza alocações de memória, mas não devolve ao sistema operacional toda a memória que foi utilizada. Normalmente isto gera no Totvs Application server o seguinte comportamento:

Após iniciar o serviço do Protheus, um ou mais usuários se conectam nele usando o SmartClient, e executam diversas aplicações durante um período de tempo. NO final do dia, depois que todos os usuários desconectarem do servidor, e não houver mais nenhum Job rodando, verificamos a memória ocupada pelo executável usando o Task Manager do Windows, e verificamos que, mesmo sem nenhuma conexão, o serviço do Application Server mantém de 200 a 300 MB de mempória alocada.

Até aqui, este é um comportamento normal, afinal as DLLs de acesso a dados não serão descarregadas até que o serviço seja finalizado, e internamente o servidor de aplicação utiliza um mecanismo de gerenciamento de memória que prioriza manter uma reserva de memória pré-alocada, que não é devolvida ao sistema operacional, o que agiliza as próximas execuções de aplicações.

Porém, após mais um dia de trabalho, depois que mais usuários executaram mais rotinas e programas, depois que o último usuário desconectou do servidor de aplicação, ele está ocupando 500 MB, e no outro dia 700 MB, e no outro dia 1 GB … Este crescimento da memória ao longo do tempo, medido depois que todos os usuários desconectaram do sistema, indica um comportamento de Leak de memória.

As causas do Leak

Em um programa AdvPL, você não tem acesso a nenhum mecanismo de alocação direta de memória explicitamente, as variáveis que você cria vão alocar memória dinamicamente para armazenar os conteúdos destas variáveis, e o servidor de aplicação têm mapas e listas de controle desses recursos. Porém, quando a execução de um processo termina, todos os recursos, variáveis, caches e etc usados por aquele processo são desalocados e a memória é (parcialmente) devolvida ao sistema operacional. Quando algum recurso interno da linguagem não fez a devolução de todas as áreas de memória, devido a uma ocorrência de processamento ou desvio lógico não previsto, uma ou mais áreas de memória formam “esquecidas” de serem devolvidas, e após o final do programa, permanecem alocadas da memória, sem referencia ao programa que as utilizava. Trata-se de uma área “perdida”, que o servidor de aplicação não vai conseguir reutilizar, e que ocupa espaço na memoria alocada.

Neste cenário, se um servidor de aplicação estiver deixando 200 Mg de Leak por dia na memória, após uma semana, a capacidade de atender conexões deste serviço vai ser prejudicada, pois ele já tem uma quantidade muito grande de memoria alocada e não utilizada, e se antes cabiam 20 usuários conectados neste serviço, com a memória ocupada, este servidor passa a aguentar apenas 15, 10 ou menos usuário, atingindo os limites de alocação de memória com menos usuários e podendo afetar a disponibilidade do ambiente ou deste serviço.

Na prática, não há nada em AdvPL que propositalmente deixe um leak na memória. Normalmente alguém esqueceu de devolver o conteúdo de um ponteiro, ou não foi prevista uma possibilidade de amarração de dados na memória, em uma condição específica, que não foi tratada adequadamente. Agora, uma coisa que é possível e relativamente comum de acontecer, é o consumo crescente de memória.

Definindo consumo crescente de memória

A determinação de um Leak é feita baseado no crescimento do saldo residual de memória alocada pelo executável de uma aplicação após os processos de execução terem sido finalizados. O Consumo crescente é caracterizado pela execução da mesma rotina, onde cada interação ou repetição do mesmo processo aloca mais memória durante o seu uso. Este consumo pode ser necessário ou intencional, ou pode ser uma falha de projeto ou lógica em um determinado componente.

Por exemplo, uma rotina de interface de consulta qualquer, que permite que o operador do sistema defina uma faixa de datas para pesquisa, e que disponibiliza estas informações na tela usando um Array AdvPL, ao invés de abrir um Browse sobre uma tabela de dados ou uma tabela temporária, fatalmente vai ocupar mais memória durante a sua execução, caso existam muitas informações a serem manipuladas.
Neste caso o desenvolvedor precisa tomar cuidado para criticar o tamanho do array, ou as informações que o usuário especifica para a pesquisa, pois o Array no AdvPL não têm limite definido de número de elementos. Ele pode se extender até ocupar toda a memória endereçável pelo servidor de aplicação AdvPL até derrubar o serviço — e todos os outros processos que nele estão sendo executados. Neste caso o consumo é intencional e necessário, mas deve ser dimensionado para não causar transtornos.

O outro cenário (falha de processo ou de lógica) pode ser caracterizado pelo seguinte cenário: Uma determinada função dentro de um fonte utiliza um array de escopo STATiC para realizar um cache de alguma coisa, e o programador esqueceu de fazer uma verificação para evitar que a mesma informação seja colocada no cache. Conforme a aplicação vai sendo executada, este array vai crescendo … após algumas horas trabalhando com a aplicação, aquele processo pode estar consumindo sozinho 400, 500 MB de memória. Porém, quando o programa é finalizado, toda a memoria ocupada (desnecessariamente) vai ser limpa.

Estes cenários são difíceis de serem identificados, requerem a habilitação dos mecanismos de monitoramento e acompanhamento dos logs gerados para levantar informações sobre quais rotinas e sob quais condições este consumo crescente é reproduzida.

Identificando o Leak

A forma mais elegante de confirmar se um consumo excessivo de memória é realmente um Leak, é utilizar as chaves DebugThreadUsedMemory=1 em conjunto da chave ServerMemoryInfo=1 ( ambas na seção [GENERAL] do appserver.ini). A primeira chave serve para ligar o consumo de memoria por processo, e a segunda faz com que o TOTVS Application Server grave no log de console ( console.log ) uma “foto” dos processos e da memória em uso em intervalos de 1 minuto, além de mostrar um status de alguns acumuladores de memória internos, depois que você finaliza o TOTVS Application Server, e todos os processos internos de execução foram finalizados.

Partindo para a prática

Insira as chaves mencionadas na seção [general] do appserver.ini, e suba o TOTVS Aplication Server em modo console. Você deve ver as seguintes informações:

Win NT/2000
[INFO ][SERVER] [Thread 7900] [SMARTHEAP] Registering Tasks...
[INFO ][SERVER] [Thread 7900] [SMARTHEAP] Version 8.0.0
*** TOTVS S.A. ***
*** www.totvs.com.br ***
TOTVS - Build 7.00.131227A - Jul 23 2015 - 06:50:20
'. TOTVS AppServer x32' console mode.
Press Ctrl+Break to terminate.
*** SERVER BUILD WITH EXTENDED PROFILER INFORMATION
*** SERVER BUILD WITH DUAL-STACK SOCKETS FOR IPV6 IMPLEMENTATION
*** DEFAULT SOCKET BIND IS IPV4
*** STARTING SERVER WITH DEBUG OF USED MEMORY PER THREAD
*** STARTING SERVER WITH PRECISION FLOATING POINT ARITHMETIC
---------------- OS System Info -----------------------------------------------
OS Version .........: Windows 8 [Version 6.2.9200]
OS Platform ........: Windows NT Based (x64)
OS Version Info ....:
-------------------------------------------------------------------------------
---------------- OS Memory Info -----------------------------------------------
Physical memory . 8084.27 MB. Used 3592.04 MB. Free 4492.23 MB.
Paging file ..... 10004.27 MB. Used 5486.12 MB. Free 4518.15 MB.
-------------------------------------------------------------------------------
[INFO ][SERVER] [Thread 7900] APP Virtual Address Allocation Limit .... 4095.88 MB.
[INFO ][SERVER] [Thread 7900] Memory Monitor Virtual Address LIMIT .... 4095.88 MB.
Http server is ready.
 Root path is c:\protheus11\http\
 Listening port 80 (default)
[INFO ][SERVER] Application PID ......... [8788]
[INFO ][SERVER] Application Main Thread .. [7900]
[INFO ][SERVER] [Thread 7900] Application Server started on port 6010
[31/07/2015 21:31:48] Server started.
----------- Total Thread Count ------------
 Total Threads ... 18
 Thread ... 3
 WThread ... 10
 SockServer ... 1
 HttpThread ... 3
 HttpServer ... 1
-------------- APO Map List ---------------
*** EMPTY ***
----------- Detailed Process List ----
[ 9156][ 0.00 MB][ Thread][ tMemoryMonitor][]
[ 4116][ 0.00 MB][ HttpServer][ tHttpServer][]
[ 8804][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 7532][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 10540][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 2072][ 0.00 MB][ Thread][ GenProcCleaner][]
[ 3252][ 0.01 MB][ SockServer][ tMainServer][]
[ 5988][ 0.00 MB][ WThread][ tWThreadBase][]
[ 3800][ 0.00 MB][ WThread][ tWThreadBase][]
[ 6472][ 0.00 MB][ WThread][ tWThreadBase][]
[ 7708][ 0.00 MB][ WThread][ tWThreadBase][]
[ 2444][ 0.00 MB][ WThread][ tWThreadBase][]
[ 10216][ 0.00 MB][ WThread][ tWThreadBase][]
[ 2892][ 0.00 MB][ WThread][ tWThreadBase][]
[ 10232][ 0.00 MB][ Thread][ tJobManager][]
[ 10864][ 0.00 MB][ WThread][ tWThreadBase][]
[ 8176][ 0.00 MB][ WThread][ tWThreadBase][]
[ 4264][ 0.00 MB][ WThread][ tWThreadBase][]
----------- Global List Info --------------
 IMAP Glb List ... 0.00 kB. Count 0
 Variable Glb List ... 0.00 kB. Count 0
 Session Glb List ... 0.00 kB. Count 0
 SymTab List ... 7.11 kB. Count 725 Hits 1035
----------- SmartHeap Pools Info ----------
 pooltString ... 67.97 kB. Count 18 Ok
 poolrContent ... 71.95 kB. Count 1 Ok
 pooltInstrVar ... 71.95 kB. Count 1 Ok
 pooltConst ... 3.98 kB. Count 0 Ok
 poolrContentTypeSimple ... 3.98 kB. Count 0 Ok
 poolrContentTypeDateTime ... 3.98 kB. Count 0 Ok
 poolrContentTypeInterval ... 3.98 kB. Count 0 Ok
 pooltDecimal ... 3.98 kB. Count 0 Ok
 poolt4GLInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltNamedVar ... 3.98 kB. Count 0 Ok
 pooltSum ... 3.98 kB. Count 0 Ok
 pooltCompare ... 3.98 kB. Count 0 Ok
 pooltLocalEnv ... 3.98 kB. Count 0 Ok
 pooltInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltDirectFunctionCall ... 3.98 kB. Count 0 Ok
 pooltApoReg ... 3.98 kB. Count 0 Ok
 pooltAssignBase ... 3.98 kB. Count 0 Ok
 pooltCodeBlock ... 7.97 kB. Count 0 Ok
 pooltCodeBlockEnv ... 3.98 kB. Count 0 Ok
 pooltCodeBlockRef ... 3.98 kB. Count 0 Ok
 pooltCodeBlockInstr ... 3.98 kB. Count 0 Ok
 pooltAPXmlDocInterface ... 3.98 kB. Count 0 Ok
 pooltClassData ... 71.95 kB. Count 380 Ok
 pooltAPXmlItem ... 3.98 kB. Count 0 Ok
 pooltPrgFunctXRefEle ... 3.98 kB. Count 0 Ok
 pooltIdentifier ... 3.98 kB. Count 0 Ok
 pooltNamedVarXVarRef ... 3.98 kB. Count 0 Ok
 pooltParmDefDet ... 3.98 kB. Count 0 Ok
 pooltVarList ... 3.98 kB. Count 0 Ok
 pooltStatList ... 7.97 kB. Count 0 Ok
 pooltParmList ... 3.98 kB. Count 0 Ok
 pooltArrayElement ... 3.98 kB. Count 0 Ok
 pooltBaseIf ... 3.98 kB. Count 0 Ok
 pooltMethod ... 71.95 kB. Count 758 Ok
 pooltFindObject ... 3.98 kB. Count 0 Ok
 pooltSelfVar ... 3.98 kB. Count 0 Ok
 pooltClassProp ... 3.98 kB. Count 0 Ok
 pooltClassInstance ... 3.98 kB. Count 0 Ok
 pooltMethodCall ... 3.98 kB. Count 0 Ok
 pooltReturn ... 3.98 kB. Count 0 Ok
 pooltStaticEnv ... 3.98 kB. Count 0 Ok
 pooltPrivateEnv ... 3.98 kB. Count 0 Ok
 Default Memory Pool ... 1663.33 kB. Count 3437 Ok
TOTAL POOLED MEMORY ... 2174.50 kB.
----------- OS Memory Summary -------------
Physical memory . 8084.27 MB. Used 3590.72 MB. Free 4493.55 MB.
Paging file ..... 10004.27 MB. Used 5503.69 MB. Free 4500.58 MB.
----------- APP Memory Summary ------------
 Server Memory Capacity ... 4095.88 MB.
 Service Used Memory ... 101.06 MB.
 Service Resident Memory ... 28.12 MB.
[INFO ][SERVER] [Thread 9156] [MEMORY] V-Load 0.02 - Peak 101.06 MB. - SL 4095.88 MB.
[INFO ][SERVER] [Thread 9156] [MEMORY] R-Load 1.00 - Peak 28.12 MB. - SL 28.12 MB.

Logo após iniciar o serviço, finalize ele usando Control+C e digitando SIM ou YES e pressionando ENTER.
Deve ser gravado um log parecido com o mostrado abaixo:

Digite SIM [Enter] (maiusculo) para sair
Type YES [Enter] (uppercase) to exit:
Wait...
[INFO ][SERVER] [Thread 9368] Application Server Console Stopped...
[INFO ][SERVER] [Thread 7900] Application Server (WIN32 version) in shutdown....
[INFO ][SERVER] [Thread 7900] [31/07/2015 21:33:07] Application SHUTDOWN in progress...
----------- Total Thread Count ------------
 Total Threads ... 18
 Thread ... 3
 WThread ... 10
 SockServer ... 1
 HttpThread ... 3
 HttpServer ... 1
-------------- APO Map List ---------------
*** EMPTY ***
----------- Detailed Process List ----
[ 9156][ 0.00 MB][ Thread][ tMemoryMonitor][]
[ 4116][ 0.00 MB][ HttpServer][ tHttpServer][]
[ 8804][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 7532][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 10540][ 0.00 MB][ HttpThread][ tHttpWThread][]
[ 2072][ 0.00 MB][ Thread][ GenProcCleaner][]
[ 3252][ 0.01 MB][ SockServer][ tMainServer][]
[ 5988][ 0.00 MB][ WThread][ tWThreadBase][]
[ 3800][ 0.00 MB][ WThread][ tWThreadBase][]
[ 6472][ 0.00 MB][ WThread][ tWThreadBase][]
[ 7708][ 0.00 MB][ WThread][ tWThreadBase][]
[ 2444][ 0.00 MB][ WThread][ tWThreadBase][]
[ 10216][ 0.00 MB][ WThread][ tWThreadBase][]
[ 2892][ 0.00 MB][ WThread][ tWThreadBase][]
[ 10232][ 0.00 MB][ Thread][ tJobManager][]
[ 10864][ 0.00 MB][ WThread][ tWThreadBase][]
[ 8176][ 0.00 MB][ WThread][ tWThreadBase][]
[ 4264][ 0.00 MB][ WThread][ tWThreadBase][]
----------- Global List Info --------------
 IMAP Glb List ... 0.00 kB. Count 0
 Variable Glb List ... 0.00 kB. Count 0
 Session Glb List ... 0.00 kB. Count 0
 SymTab List ... 7.11 kB. Count 725 Hits 1035
----------- SmartHeap Pools Info ----------
 pooltString ... 71.95 kB. Count 18 Ok
 poolrContent ... 71.95 kB. Count 1 Ok
 pooltInstrVar ... 71.95 kB. Count 1 Ok
 pooltConst ... 3.98 kB. Count 0 Ok
 poolrContentTypeSimple ... 3.98 kB. Count 0 Ok
 poolrContentTypeDateTime ... 3.98 kB. Count 0 Ok
 poolrContentTypeInterval ... 3.98 kB. Count 0 Ok
 pooltDecimal ... 3.98 kB. Count 0 Ok
 poolt4GLInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltNamedVar ... 3.98 kB. Count 0 Ok
 pooltSum ... 3.98 kB. Count 0 Ok
 pooltCompare ... 3.98 kB. Count 0 Ok
 pooltLocalEnv ... 3.98 kB. Count 0 Ok
 pooltInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltDirectFunctionCall ... 3.98 kB. Count 0 Ok
 pooltApoReg ... 3.98 kB. Count 0 Ok
 pooltAssignBase ... 3.98 kB. Count 0 Ok
 pooltCodeBlock ... 7.97 kB. Count 0 Ok
 pooltCodeBlockEnv ... 3.98 kB. Count 0 Ok
 pooltCodeBlockRef ... 3.98 kB. Count 0 Ok
 pooltCodeBlockInstr ... 3.98 kB. Count 0 Ok
 pooltAPXmlDocInterface ... 3.98 kB. Count 0 Ok
 pooltClassData ... 71.95 kB. Count 380 Ok
 pooltAPXmlItem ... 3.98 kB. Count 0 Ok
 pooltPrgFunctXRefEle ... 3.98 kB. Count 0 Ok
 pooltIdentifier ... 3.98 kB. Count 0 Ok
 pooltNamedVarXVarRef ... 3.98 kB. Count 0 Ok
 pooltParmDefDet ... 3.98 kB. Count 0 Ok
 pooltVarList ... 3.98 kB. Count 0 Ok
 pooltStatList ... 7.97 kB. Count 0 Ok
 pooltParmList ... 3.98 kB. Count 0 Ok
 pooltArrayElement ... 3.98 kB. Count 0 Ok
 pooltBaseIf ... 3.98 kB. Count 0 Ok
 pooltMethod ... 71.95 kB. Count 758 Ok
 pooltFindObject ... 3.98 kB. Count 0 Ok
 pooltSelfVar ... 3.98 kB. Count 0 Ok
 pooltClassProp ... 3.98 kB. Count 0 Ok
 pooltClassInstance ... 3.98 kB. Count 0 Ok
 pooltMethodCall ... 3.98 kB. Count 0 Ok
 pooltReturn ... 3.98 kB. Count 0 Ok
 pooltStaticEnv ... 3.98 kB. Count 0 Ok
 pooltPrivateEnv ... 3.98 kB. Count 0 Ok
 Default Memory Pool ... 1663.33 kB. Count 3439 Ok
TOTAL POOLED MEMORY ... 2178.48 kB.
----------- OS Memory Summary -------------
Physical memory . 8084.27 MB. Used 3592.28 MB. Free 4492.00 MB.
Paging file ..... 10004.27 MB. Used 5494.38 MB. Free 4509.89 MB.
----------- APP Memory Summary ------------
 Server Memory Capacity ... 4095.88 MB.
 Service Used Memory ... 100.67 MB.
 Service Resident Memory ... 28.04 MB.
**
[INFO ][SERVER] [Thread 9156] Memory Monitor END
...
/* =========================================================================
*** SMARTHEAP POOL STATUS AFTER FINISHED PROCESSES ***
pooltString ... 71.95 kB. Count 0 Ok
 poolrContent ... 71.95 kB. Count 0 Ok
 pooltInstrVar ... 71.95 kB. Count 0 Ok
 pooltConst ... 3.98 kB. Count 0 Ok
 poolrContentTypeSimple ... 3.98 kB. Count 0 Ok
 poolrContentTypeDateTime ... 3.98 kB. Count 0 Ok
 poolrContentTypeInterval ... 3.98 kB. Count 0 Ok
 pooltDecimal ... 3.98 kB. Count 0 Ok
 poolt4GLInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltNamedVar ... 3.98 kB. Count 0 Ok
 pooltSum ... 3.98 kB. Count 0 Ok
 pooltCompare ... 3.98 kB. Count 0 Ok
 pooltLocalEnv ... 3.98 kB. Count 0 Ok
 pooltInterFunctionCall ... 3.98 kB. Count 0 Ok
 pooltDirectFunctionCall ... 3.98 kB. Count 0 Ok
 pooltApoReg ... 3.98 kB. Count 0 Ok
 pooltAssignBase ... 3.98 kB. Count 0 Ok
 pooltCodeBlock ... 7.97 kB. Count 0 Ok
 pooltCodeBlockEnv ... 3.98 kB. Count 0 Ok
 pooltCodeBlockRef ... 3.98 kB. Count 0 Ok
 pooltCodeBlockInstr ... 3.98 kB. Count 0 Ok
 pooltAPXmlDocInterface ... 3.98 kB. Count 0 Ok
 pooltClassData ... 71.95 kB. Count 0 Ok
 pooltAPXmlItem ... 3.98 kB. Count 0 Ok
 pooltPrgFunctXRefEle ... 3.98 kB. Count 0 Ok
 pooltIdentifier ... 3.98 kB. Count 0 Ok
 pooltNamedVarXVarRef ... 3.98 kB. Count 0 Ok
 pooltParmDefDet ... 3.98 kB. Count 0 Ok
 pooltVarList ... 3.98 kB. Count 0 Ok
 pooltStatList ... 7.97 kB. Count 0 Ok
 pooltParmList ... 3.98 kB. Count 0 Ok
 pooltArrayElement ... 3.98 kB. Count 0 Ok
 pooltBaseIf ... 3.98 kB. Count 0 Ok
 pooltMethod ... 71.95 kB. Count 0 Ok
 pooltFindObject ... 3.98 kB. Count 0 Ok
 pooltSelfVar ... 3.98 kB. Count 0 Ok
 pooltClassProp ... 3.98 kB. Count 0 Ok
 pooltClassInstance ... 3.98 kB. Count 0 Ok
 pooltMethodCall ... 3.98 kB. Count 0 Ok
 pooltReturn ... 3.98 kB. Count 0 Ok
 pooltStaticEnv ... 3.98 kB. Count 0 Ok
 pooltPrivateEnv ... 3.98 kB. Count 0 Ok
 Default Memory Pool ... 1003.36 kB. Count 156 Ok
TOTAL POOLED MEMORY ... 1518.52 kB.
========================================================================= */

No momento que o Totvs Application Server inicia o “shutdown” do serviço, são mostrados os processos de execução AdvPL ( no nosso caso nenhum ), os processos internos ( Detailed Process List ), e os acumuladores de memória internos do Application Server em uso. Depois que todos os processos foram encerrados internamente, é mostrada uma nova foto dos acumuladores de memória, logo após a mensagem “*** SMARTHEAP POOL STATUS AFTER FINISHED PROCESSES ***”

Reparem que todos os acumuladores estão com o contador ZERO, exceto o Default Memory Pool, com 156 buffers. Este é o comportamento esperado de um servidor de aplicação sem Leak. O acumulador do Default Memory Pool pode variar um pouco, entre 180 e 220 elementos, as vezes mais ou menos … porém os demais acumuladores precisam estar com o contador ZERO após a mensagem “*** SMARTHEAP POOL STATUS AFTER FINISHED PROCESSES ***”. Caso exista um ou mais ( quando aparecem são sempre mais de um ) acumuladores com contador maior que zero, algum programa durante a sua execução deixou ponteiros de memória não referenciados sem desalocar a memória. Isso caracteriza a existência de Leak.

Achando o “culpado”

Agora vêm a parte difícil … Normalmente um servidor de aplicação AdvPL executa diversos códigos e rotinas de vários usuários, diariamente. Uma ou mais destas rotinas durante a sua execução não liberaram alguma porção da memória. Descobrir qual delas é o desafio. Normalmente a garimpagem desses dados é realizada com procedimentos de paradas mais frequentes dos serviços do TOTVS Application Server, e a geração do log de console desde o momento que o serviço foi iniciado.

A cada parada, verificamos se houve leak registrado no final, e verificamos pelos logs as rotinas executadas, e verificamos também se alguns erros críticos específicos foram registrados durante a execução do serviço.

Culpado No 1 : Access Violation e “Failure on Thread Delete”

Qualquer ocorrência de Access Violation ( ou violação de endereço de memória ) registrada pode interromper ou impedir a execução da finalização normal de um processo, o que pode deixar memória alocada após o final do processo, ou pior: Conexões com o DBAccess e com o License Server , arquivos abertos no disco, registros bloqueados no DBAccess, etc… PAra as aplicações endereçadas por estas conexões, a conexão ainda está ativa, pois o processo não foi totalmente finalizado. Neste caso, estes recursos somente serão liberados quando você finalizar o servidor de aplicação — parar o serviço do Tots Application Server.

Quando temos uma ocorrência de Access Violation, devemos verificar onde ela é reproduzida, se ela acontece em um ou mais programas, e tentar fazer uma receita de bolo para reproduzir a ocorrência, abrindo um chamado na Totvs. Caso não seja possível determinar uma receita de bolo para reproduzir o problema, o que caracteriza uma ocorrência esporádica, normalmente é disponibilizado ao cliente uma build “Debug” do TOTVs Application SErver. Esta build é capaz de gerar um arquivo chamado “core_nnnn.dmp”, contendo uma foto da memória inteira do TOTVS Application Server, no momento em que aconteceu um Access Violation. A análise deste log ajuda o departamento de tecnologia a identificar o que aconteceu.

Normalmente cada nova liberação dos executáveis e DLLS que compõe o TOTVS Application Server possuem correções, melhorias e proteções das situações encontradas entre os releases que podem ser a causa provável de uma ocorrência desta natureza. Por isso a TOTVS recomenda que o cliente esteja com a última build atualizada e liberada no Portal. Caso o Access Violation aconteça na última build, é gerada uma Build DEBUG do Application Server da última build para a avaliação da ocorrência.

Culpado No 2 : Impressões no servidor usando um Driver com interface

Caso você use a impressão do ERP para o Pool de impressão do Windows no servidor (e não no SmartClient), e você tenha no servidor um driver de geração de PDF (por exemplo), e o TOTVS Application Server sendo executado como serviço… caso você dispare uma impressão para este driver, ele vai tentar abrir uma caixa de diálogo na máquina onde está sendo executado o Totvs Application Server … mas como o APPServer está sendo executado como serviço, além disso não ser possível, isso literalmente TRAVA aquele processo, mantendo todos os recursos abertos, conexão com o DBAccess, processo preso no Protheus Monitor, conexão aberta no License Server, etc… Fatalmente, quando você tentar parar o serviço do Totvs Application Server, ele não vai sair … você vai precisar literalmente “chutar” o processo pelo TasK Manager do Windows. Cada processo que ficou travado vai permanecer como um “zumbi” no APPServer, e o acúmulo destes processos vai afetar a memória disponível para a execução dos programas.

Culpado No 3 : Falha de algum recurso do AdvPL

Durante a execução de um programa, alguma das funções ou classes chamadas não desalocou um ou mais ponteiros de memória, normalmente isso acontece quando uma situação particular nos destrutores não foi prevista. Neste caso, deve ser feita aquela garimpagem nos logs gerados durante a execução do Appllication Server, inclusive comparando logs onde houve a geração de leak e onde não houve a geração de leak, para tentar identificar quais programas são os possiveis candidatos, para fazer um teste pontual: Subir um TOTVs Application Server isolado, onde apenas um usuário conecta, e testa um programa. Após o usuário terminar o programa, o servidor é baixado, e o log deve ser verificado para ver se houve Leak.

Houve umm caso de Leak de memória que somente era reproduzido quando o usuário entrava no ERP pelo SIGAADV, e após o Menu do ERP ser mostrado, o usuário clicava e um “cadeado” na interface para trocar de módulo, e após realizar a troca de módulo pelo menos uma vez, a primeira janela da troca de módulo com todos os seus componentes e variáveis era “largada” na memória, ocupando um espaço significativo, obrigando os administradores do ambiente a reiniciar os serviços do Protheus antes do inicio do expediente.

A descoberta da causa desta ocorrência somente foi possível após analisar os logs de execução de vários serviços, e perguntando para os usuários qual foi o roteiro de trabalho deles durante o dia, comparando com o roteiro de trabalho de outros usuários que executaram as mesmas rotinas, mas não houve registro de leak no servidor usados por eles. Após fazer um teste usando uma rotina e trocando de módulo, foi percebido que somente neste caso o Leak era gerado.

Não é fácil encontrar um Leak nem um Access Violation. Uma vez que exista uma receita de bolo que sempre reproduza sempre o problema, o departamento de tecnologia consegue atuar, e muitas vezes propor um contorno. O difícil está em encontrar qual é a receita.

Uma vez que seja comprovada a existência de um Leak, é possível a geração de uma build de gaveta ( normalmente partindo da ultima versão liberada) com uma instrumentação específica para ajudar a encontrar ou a chegar perto do ponto que “sobrou” na memória, porém esta instrumentação deixa o processamento um pouco mais pesado.

Conclusão

Existem caminhos para chegar até a raiz do problema, alguns não são tão fáceis, tudo é diretamente proporcional a complexidade do problema. Espero que estas informações deem a todos alguma “luz” no fim do túnel e um ponto sólido de partida.

Abraços, e até o próximo post, pessoal 😀

Referências

PROBLEMA. In: WIKIPÉDIA, a enciclopédia livre. Flórida: Wikimedia Foundation, 2014. Disponível em: <https://pt.wikipedia.org/w/index.php?title=Problema&oldid=40832056>. Acesso em: 29 jul. 2015.

Anúncios

2 comentários sobre “Identificando Problemas – Memória no AdvPL – Parte 01

Deixe um comentário

Preencha os seus dados abaixo ou clique em um ícone para log in:

Logotipo do WordPress.com

Você está comentando utilizando sua conta WordPress.com. Sair / Alterar )

Imagem do Twitter

Você está comentando utilizando sua conta Twitter. Sair / Alterar )

Foto do Facebook

Você está comentando utilizando sua conta Facebook. Sair / Alterar )

Foto do Google+

Você está comentando utilizando sua conta Google+. Sair / Alterar )

Conectando a %s