Quais são alguns padrões e antipadrões do registro de aplicativos? [fechadas]

66

Recentemente, tive que investigar um problema de campo para nosso aplicativo corporativo de grande porte. Fiquei horrorizado com os logs que tive que vasculhar na tentativa de encontrar o problema e, no final do dia, os logs não ajudaram em nada a identificar / isolar o bug.

Nota: Entendo que nem todos os erros são detectáveis ​​através de logs. Isso não altera o fato de que os logs são horríveis.

Existem alguns problemas óbvios em nosso registro que já podemos tentar corrigir. Não quero listá-las aqui e não posso simplesmente mostrar nossos arquivos de log para que você possa dar conselhos sobre o que fazer.

Em vez disso, para avaliar o quão ruim estamos no setor de extração de madeira, eu gostaria de saber:

  1. Quais são algumas diretrizes , se houver, quando se trata de registrar um aplicativo, especialmente um aplicativo grande.
  2. Existem padrões que devemos seguir ou antipadrões que devemos estar cientes?
  3. Isso é importante para corrigir ou pode ser corrigido ou todos os arquivos de log são simplesmente enormes e você precisa de scripts adicionais para analisá-los?

Nota lateral: usamos log4j.

c_maker
fonte

Respostas:

55

Alguns pontos que minha prática se mostrou útil:

  • Mantenha todo o código de log no seu código de produção. Possibilidade de habilitar o log de produção mais / menos detalhado, de preferência por subsistema e sem reiniciar o programa.

  • Facilite a análise dos logs aos grepolhos. Atenha-se a vários campos comuns no início de cada linha. Identifique o tempo, a gravidade e o subsistema em todas as linhas. Formule claramente a mensagem. Facilite o mapeamento de todas as mensagens de log para sua linha de código-fonte.

  • Se ocorrer um erro, tente coletar e registrar o máximo de informações possível. Pode levar muito tempo, mas não há problema porque o processamento normal falhou de qualquer maneira. Não é necessário aguardar quando a mesma condição ocorre na produção com um depurador conectado não tem preço.

Os logs são principalmente necessários para monitorar e solucionar problemas. Coloque-se no lugar de um solucionador de problemas e pense em que tipo de registro você gostaria de ter quando algo de errado está acontecendo ou aconteceu na calada da noite.

9000
fonte
10
Gosto dessa resposta, mas gostaria de acrescentar que é importante registrar as escolhas feitas nos pontos de decisão. Eu já vi muitos sistemas em que um monte de lixo eletrônico foi registrado, mas as principais decisões não foram registradas. Portanto, 95% do log é basicamente inútil. Também para sistemas do tipo solicitação / resposta, é mais importante poder registrar por solicitação do que por subsistema.
Kevin
4
+1. Eu gosto do seu ponto de colocar-se no lugar de um solucionador de problemas. Parece que as declarações de registro deve conter muito mais mensagens de qualidade, então o que temos vindo a fazer ...
c_maker
11
É importante observar que o log de erros deve ser registrado no log de eventos apropriado e nos logs do aplicativo.
Steven Evers
2
@SnOrfus: Existem várias maneiras de armazenar logs, mas a essência é que as mensagens precisam estar disponíveis até o último segundo em que o sistema travou - como uma caixa preta de uma aeronave. Se você usar qualquer tipo de buffer, forneça uma opção para ignorá-lo / liberar todas as mensagens.
rwong
11
@Rig: por outro lado, muitos madeireiros locais não implementaram nenhum buffer (e cumpriram todas as mensagens), levando a um desempenho muito ruim. É por isso que deve ser opcional.
rwong
28

Eu trabalho com sistemas críticos de segurança em tempo real, e a criação de logs geralmente é a única maneira de detectar bugs raros que aparecem uma vez na lua azul a cada 53ª terça-feira quando é lua cheia, se você entender minha tendência. Isso meio que deixa você obsessivo com o assunto, então peço desculpas agora se começar a espuma na boca. O seguinte foi escrito para logs de depuração de código nativo, mas a maioria também é aplicável ao mundo gerenciado ...

Use arquivos de log de texto. Parece óbvio, mas algumas pessoas tentam gerar arquivos de log binários: isso é idiota, porque eu não preciso procurar uma ferramenta de leitura quando estou em campo. Além disso, se for texto e a depuração for detalhada, há uma boa chance de o engenheiro de campo ler o arquivo e diagnosticar o problema sem nunca voltar para mim. Todo mundo ganha.

Projecto sistemas capazes de registrar praticamente tudo, mas por padrão não ligo tudo. As informações de depuração são enviadas para uma caixa de diálogo de depuração oculta, que as marca e as envia para uma caixa de listagem (limitada a cerca de 500 linhas antes da exclusão), e a caixa de diálogo permite que eu pare, salve-a automaticamente em um arquivo de log ou desvie-a para um depurador conectado. Esse desvio me permite ver a saída de depuração de vários aplicativos, tudo serializado ordenadamente, que às vezes pode salvar vidas. Eu costumava usar níveis de registro numérico (quanto mais alto você define o nível, mais captura):

off
errors only
basic
detailed
everything

mas isso é muito inflexível - à medida que você trabalha em direção a um bug, é muito mais eficiente concentrar-se em fazer exatamente o que você precisa sem precisar percorrer toneladas de detritos e pode ser um tipo específico de transação ou operação Isso causa o erro. Se isso exigir que você ligue tudo, você está apenas dificultando seu próprio trabalho. Você precisa de algo mais refinado.

Então agora estou no processo de mudar para o log com base em um sistema de sinalização. Tudo o que é registrado tem um sinalizador detalhando que tipo de operação é, e há um conjunto de caixas de seleção que permitem definir o que é registrado. Normalmente, essa lista fica assim:

#define DEBUG_ERROR          1
#define DEBUG_BASIC          2
#define DEBUG_DETAIL         4
#define DEBUG_MSG_BASIC      8
#define DEBUG_MSG_POLL       16
#define DEBUG_MSG_STATUS     32
#define DEBUG_METRICS        64
#define DEBUG_EXCEPTION      128
#define DEBUG_STATE_CHANGE   256
#define DEBUG_DB_READ        512
#define DEBUG_DB_WRITE       1024
#define DEBUG_SQL_TEXT       2048
#define DEBUG_MSG_CONTENTS   4096

Esse sistema de registro é fornecido com a compilação do release , ativada e salva em arquivo por padrão. É muito tarde para descobrir que você deveria estar registrando APÓS o bug ter ocorrido, se esse bug ocorrer apenas uma vez a cada seis meses em média e você não tiver como reproduzi-lo. O registro que funciona apenas com compilações de depuração é justo. avião. idiota.

O software normalmente é fornecido com ERROR, BASIC, STATE_CHANGE e EXCEPTION ativado, mas isso pode ser alterado no campo através da caixa de diálogo de depuração (ou uma configuração de registro / ini / cfg, onde essas coisas são salvas).

Ah, e uma coisa - meu sistema de depuração gera um arquivo por dia. Seus requisitos podem ser diferentes. Mas verifique se o seu código de depuração inicia todos os arquivos com a data, a versão do código que você está executando e, se possível, com algum marcador para o ID do cliente, a localização do sistema ou o que for. Você pode obter uma mistura de arquivos de log vindo do campo e precisa de algum registro do que veio de onde e qual versão do sistema eles estavam executando, que está realmente nos próprios dados e não pode confiar no cliente / engenheiro de campo para dizer qual versão eles têm - eles podem apenas dizer qual versão eles pensam que têm. Pior, eles podem relatar a versão exe que está no disco, mas a versão antiga ainda está em execução porque se esqueceu de reiniciar após a substituição. Faça com que seu código diga a si mesmo.

Por fim, você não deseja que seu código gere seus próprios problemas; portanto, coloque uma função de timer para limpar os arquivos de log após tantos dias ou semanas (basta verificar a diferença entre a hora atual e a hora da criação do arquivo). Isso é bom para um aplicativo de servidor que é executado o tempo todo; em um aplicativo do lado do cliente, você pode limpar todos os dados antigos ao iniciar. Normalmente, limpamos após 30 dias ou mais, em um sistema sem visitas frequentes ao engenheiro, talvez você queira deixá-lo por mais tempo. Obviamente, isso também depende do tamanho dos seus arquivos de log.

Bob Moore
fonte
11
+1 Em geral, excelente resposta, mas especialmente para colocar o ID do aplicativo e as informações da versão no arquivo de log, infelizmente isso é esquecido com muita frequência.
Binary Worrier
27

Meu recurso público favorito para diretrizes de registro em log é o Apache JCL Best Practices .

As melhores práticas para JCL são apresentadas em duas categorias: Geral e Empresa. Os princípios gerais são bastante claros. As práticas corporativas são um pouco mais envolvidas e nem sempre é claro o porquê de serem importantes.

Os princípios de boas práticas corporativas se aplicam aos componentes e ferramentas de middleware que se espera executar em um ambiente de nível "Corporativo". Esses problemas estão relacionados ao registro como internacionalização e detecção de falhas. A empresa requer mais esforço e planejamento, mas é fortemente incentivada (se não for necessária) nos sistemas em nível de produção. Diferentes empresas / ambientes corporativos têm requisitos diferentes, portanto, ser flexível sempre ajuda ...

Apesar de direcionar a JCL, elas parecem ser genéricas o suficiente para serem adotadas para o log em geral.

  • Minhas "diretrizes" pessoais para o registro são que, no nível de depuração, tento fazer com que meus registros sejam lidos como uma história - com lógica compreensível e detalhes suficientes (mas não sobrecarregados).

O anti-padrão mais famoso é provavelmente "engolir exceções" - basta pesquisar na web por ele.

Quanto aos grandes arquivos de registro, na minha prática, esse era o caso normal. E sim, scripts suplementares como você os chama e / ou ferramentas como o Chainsaw também parecem normais para mim.

  • Acima não significa, porém, que você sempre deve colocar cegamente todos os logs em um arquivo enorme. Às vezes, pode ser útil escrever / copiar alguns dos logs para separar arquivos. Por exemplo, em meu projeto recente, os funcionários de controle de qualidade pediram arquivos dedicados para métricas e dados de tempo e para breves relatórios sobre as operações do sistema. Eles disseram que se beneficiariam disso e o fizeram (o benefício de um breve arquivo de relatórios foi realmente significativo).

PS. Em relação aos antipadrões, outros que vêm à mente são mensagens "inundadas" e sem sentido.

  • Chamo de inundação quando vejo várias mensagens semelhantes provenientes de um loop com muitas iterações. Para mim, as inundações são irritantes o suficiente para tentar me livrar delas quando a detecto no código fonte. Geralmente, melhorá-lo requer alguma arte - porque, bem, as coisas que acontecem dentro do loop podem ser interessantes. Quando não tenho tempo para aprimorá-lo mais, tento alterar pelo menos o nível de log dessas mensagens para o mais baixo, para facilitar a filtragem.

  • Mensagens sem sentido parecem ser um lixo bastante popular. Eles parecem inofensivos quando lidos no código fonte - acho que é preciso passar pela dor de analisar a saída de depuração parecida com ...

    step #1
    step #2
    step #3
    

    ... para apreciar profundamente sua feiura inerente. Minha heurística favorita para detectar esse tipo de problema no nível do código-fonte (proposto por um colega em um dos meus projetos anteriores) é calcular o número de ocorrências de símbolos de espaço em literais de string usados ​​no log. Na minha experiência, zero espaços basicamente garante que a instrução de log não faz sentido, um espaço também é um bom indicador do possível problema.

mosquito
fonte
4
Para evitar inundações, costumo reunir as heurísticas do loop e produzi-lo após o loop. Significando que qualquer coisa interessante que esteja acontecendo no loop deve ser armazenada em uma variável (como somethingSpecialHappenedCount) e depois enviada para o criador de logs.
Spoike 5/10/11
@ Spike bom ponto! armazenar em uma variável é realmente um dos meus truques favoritos pessoais para combater enchentes
mosquito
11
Eu produzo todos os contadores diferentes para o criador de logs como uma tabela ASCII no log após o término do loop, para que eles possam ser comparados facilmente. A ideia da tabela foi inspirada na que o StopWatch.prettyPrint () da Spring gera. Fora isso, tornar o texto do log legível e relevante ainda é uma "arte", como mencionado anteriormente na resposta.
Spoike 5/10/11
@ Spike: (e @gnat) Isso é interessante. Então, basicamente, você adiciona código real à lógica de negócios apenas para fins de registro? Eu nunca ouvi falar disso ou fiz isso antes e não tenho certeza de como justificaria isso para meus colegas de trabalho. Receio que, se começarmos a fazer isso, alguns de nossos desenvolvedores bagunçam o código-fonte a tal ponto que a lógica de negócios se torne complicada e difícil de ler. Simplesmente registrar uma declaração já está tornando a fonte mais feia.
c_maker
2
@c_maker Seu ponto de vista sobre a combinação de log com lógica de negócios parece valer uma pergunta dedicada. Pessoalmente, ainda não tenho uma opinião forte sobre esses assuntos. Em teoria, pode-se imaginar algumas melhorias de separação usando AOP e iirc; existem até aplicações práticas para essa abordagem. Na prática, no entanto, continuo com a abordagem "mista" e até agora não tive grandes problemas com ela. O código-fonte desorganizado é um perigo real, mas, novamente, até agora eu consegui coexistir com o código de log bastante "pacificamente". É claro que isso requer certo esforço.
mosquito
11

Registre a exceção apenas uma vez!

Um dos pontos problemáticos comuns que notei é o registro e a repetição de uma exceção. Como resultado, os arquivos de log contêm as mesmas exceções várias vezes em vários níveis de pilha.

Nayaki
fonte
5

Aqui está um antipadrão: Criar duas dúzias de campos "genéricos" em uma tabela de banco de dados para rastrear qualquer coisa concebível e, em seguida, ter 88 (e contar) valores de enumeração diferentes para diferentes tipos de logs.

Wayne Molina
fonte
+1 - eu já vi isso. "Tabelas de erros" que possuem colunas como string1, string2, string3, string4, string5, em que concatinar todas as colunas resultará em um código de erro que não é mencionado em nenhuma documentação. O resultado é um log confuso e inútil; também conhecido como "aplicativo corporativo de terceiros com inferno de depuração de desenvolvimento personalizado".
Morgan Herlocker 5/10
No meu caso é "sistema de registro enrolado à mão sem qualquer ideia do que logging realmente envolve"
Wayne Molina
4

Minha experiência com logs é quanto maior, melhor, mas seja consistente o suficiente para torná-lo filtrável por máquina e seja capaz de configurar um nível de severidade para cada componente do seu aplicativo individualmente.

Além disso, é muito difícil prever qual registro você precisará para encontrar um bug futuro. A maioria dos locais óbvios para registrar erros é corrigida antes que o produto saia pela porta. Não é incomum que o resultado de um relatório de bug seja que você acabou de adicionar o log para ajudar a diagnosticá-lo se isso acontecer novamente.

Karl Bielefeldt
fonte
2

Algumas notas do lado de operações da casa aqui:

1) Verifique se os logs são configuráveis ​​localmente, de preferência com uma ferramenta não mais pesada que um editor de texto. Na maioria das vezes, não queremos obter o registro no nível TRACE, mas gostamos de poder ativá-lo.

2) Se possível, verifique se os logs podem ser lidos com uma ferramenta não mais pesada que um editor de texto. Nada é pior do que ter que ir em uma busca de ferramentas em uma hora ímpar, quando o sistema de produção está falhando.

Wyatt Barnett
fonte
1

De minha própria experiência trabalhando com aplicativos da Web:

(e considerando o armazenamento é muito barato hoje em dia)

  • Registre o máximo possível de informações disponíveis (naquele exato momento).
  • Eu sempre incluo DateTime.Now nas minhas seqüências de log.
  • Eu sempre (se possível) registro a duração do tempo de alguma "ação" específica.
  • Seja consistente com suas seqüências de log. Desde sempre eu uso esse tipo de padrão:

    • "[Info X] [Info Y] [Info Z] [etc.]"
sabiland
fonte
1

Além do rastreamento de pilha, registre o estado atual do aplicativo e a entrada.

O software é determinístico, esses dois geralmente são a única coisa que você precisa para reproduzir o bug. O armazenamento do estado completo pode, em alguns casos, ser problemático, portanto, maneiras de reproduzir o estado atual, por exemplo, por entradas anteriores, também são boas.

É claro que mais dados são sempre melhores, mas no mínimo esses dois são um bom começo para as falhas mais fáceis.

ladida
fonte
3
"Software é determinístico" => nem sempre infelizmente. Pense em erros de concorrência, por exemplo.
Assillias 26/10/12