Uso de formato de saída JSON no db2diag

O db2diag.log é o registo central de diagnóstico da instância Db2 e é juntamente com o log de notificação, um dos primeiros elementos a consultar quando há falhas de ligação, problemas de lock, deadlocks ou comportamentos inesperados do motor Db2. O problema sempre foi a forma de acesso aos dados: texto livre, diversidade de opções, campos posicionais e parsing frágil para quem quer automatizar a análise.

O Db2 12.1.3.0 introduz a opção -json no comando db2diag. Quando usada, os dados de saída do comando passam a ser JSON Lines: um objeto JSON por linha, com campos estruturados que podem ser filtrados e agregados com jq. O objetivo deste artigo é mostrar o que se consegue fazer com essa formatação JSON. O caso dos lock timeouts e deadlocks é apenas o exemplo prático usado para tornar visível a diferença entre texto livre e dados estruturados.

1. Objectivos e introdução do lab

Ao terminar este lab, deverá conseguir:

• perceber que tipo de análise fica mais fácil com db2diag -json
• identificar os parâmetros que controlam o registo de diagnóstico e de eventos de lock
• Entender a abordagem do db2diag com formatação tradicional e perceber as suas limitações
• usar db2diag -json para explorar os campos disponíveis numa mensagem concreta
• transformar a saída JSON em tabelas legíveis com jq e column
• criar um template reutilizável para repetir a análise no futuro

A ideia é mostrar porque é que a saída JSON melhora a triagem, a correlação e a automação quando o Db2 começa a produzir eventos de diagnóstico difíceis de ler manualmente.

2. O que vai necessitar para executar o lab

Vai ser necessário:

• Db2 LUW 12.1.3.0 ou superior
• Sistema Linux (atenção às versões mínimas. Para RedHat deverá usar 9.4 or superior, para Ubuntu, 22.04.5 ou superior)
• Acesso ao utilizador da instância Db2
• jq
• column
• awk, grep, sed, bash e utilitários de shell normais

Se ainda não tiver o Db2 instalado, obtenha-o através do portal oficial da IBM para downloads de software ou através do mecanismo de distribuição associado à sua licença/entitlement. O Db2 Community Edition será suficiente.

Se necessário, instale o Db2 (instalação típica serve) e crie a instância a usar no lab.

Para instalar o software auxiliar, execute:

Em RHEL, Rocky, AlmaLinux, SLES

sudo dnf install -y jq util-linux

Em Debian ou distribuições baseadas em Debian

sudo apt-get install -y jq util-linux

Os comandos abaixo deverão ser executados com a conta proprietário da instância Db2.

Os parâmetros que vamos alterar são:

Para este lab:

3. Mecanismos tradicionais de visualização do diagnóstico

db2diag

O comando db2diag continua a ser a ferramenta central para ler o db2diag.log. Permite filtrar por nível de severidade e por intervalo temporal e outros critérios, tem opções básicas de formatação e pesquisa e é útil quando está a investigar um incidente em tempo real.

Exemplo:

db2diag -t "$(date -d '1 hour ago' '+%Y-%m-%d-%H.%M.%S')" -l Warning,Error,Severe

Existem, no entanto, algumas limitações:

• É difícil agregar por pid, tid, componente ou função sem processamento adicional de parsing.
• Mensagens com campos aninhados obrigam a regex ou mecanismos frágeis de parsing.
• O grep trabalha linha a linha e mesmo que possamos pedir conteúdo de linhas adjacentes, não entende o contexto completo de um bloco de diagnóstico.
• Exportar para CSV ou correlacionar eventos exige mais trabalho do que deveria.

Vistas administrativas

Vistas administrativas, como SYSIBMADM.PDLOGMSGS_LAST24HOURS, são úteis para monitorização operacional, fornecem a flexibilidade da utilização de SQL, mas lêem o log de notificações de notificação e não o db2diag.log. São boas para eventos de arranque, paragem e análise de alto nível de eventos operacionais.

Exemplo:

db2 connect to DIAGJSON
db2 "SELECT TIMESTAMP, MSGSEVERITY, SUBSTR(MSG,1,256) AS MSG FROM SYSIBMADM.PDLOGMSGS_LAST24HOURS ORDER BY TIMESTAMP DESC FETCH FIRST 20 ROWS ONLY"

As principais limitações são:

• Dependem que a instância Db2 esteja operacional
• Não mostram todos os detalhes do diagnóstico interno

Table functions e monitorização SQL

As table functions e vistas de monitorização ajudam em dashboards e observabilidade contínua, mas também dependem de uma instância Db2 operacional. São muito úteis quando a instância e a base de dados estão saudável mas são muito menos úteis quando não estão e o problema é precisamente o motivo pelo qual quer visualizar a informação de diagnóstico.

Em resumo:

• db2diag é a fonte mais próxima do evento real.
• As vistas e funções SQL são boas para observabilidade quando o sistema está saudável.

4. Suporte de formato JSON no Db2 (db2diag -json)

A partir do Db2 12.1.3.0, podemos incluir a opção -json no comando db2diag.

Isto muda duas coisas:

• Os dados de saída passam a ser JSON Lines, com um objeto JSON por linha
• Os campos passam a ser acessíveis de forma estruturada, sem necessidade de parsing de texto livre

Existem várias vantagens:

• Fornecimento dos dados num formato estruturado que pode ser consumido mais facilmente por plataformas de observabilidade
• Uso de ferramentas que processem JSON, como por exemplo, o jq de forma a efetuar exploração flexível dos dados.

Para o tipo de análise que abordamos no artigo, o JSON não substitui o db2diag clássico mas complementa-o. Use a formatação tradicional para inspeção rápida e o JSON quando necessitar de maior flexibilidade na filtragem, parsing e formatação.

5. Cenário e execução do Lab.

Vamos criar uma base de dados, objetos de schema e preencher os dados destes e em seguida vamos gerar várias “lock timeouts” e uma situação de “deadlock” para provocar registos de contenção semelhantes no db2diag.log. Vamos explorar a informação de diagnóstico usando a nova capacidade de formatação JSON.

Estabelecer a configuração necessária a nível de bases de dados e instância

Vamos começar por criar a base de dados e estabelecer as configurações necessárias na instância e base de dados Db2.

db2 create database DIAGJSON
db2 connect to DIAGJSON
db2 "UPDATE DB CFG FOR DIAGJSON USING LOCKTIMEOUT 5 MON_LCK_MSG_LVL 3"
db2 update dbm cfg using DIAGLEVEL 3 NOTIFYLEVEL 3
db2stop force
db2start

Para confirmar os valores, execute:

db2 get dbm cfg | grep -iE "diaglevel|notifylevel"
db2 get db cfg for DIAGJSON | grep -iE "locktimeout|mon_lck_msg_lvl"

Vamos agora criar os objectos de schema necessários e introduzir os dados:

db2 connect to DIAGJSON
db2 "CREATE SCHEMA app"
db2 "CREATE TABLE app.accounts (id INTEGER NOT NULL, balance DECIMAL(10,2), PRIMARY KEY (id))"
db2 "INSERT INTO app.accounts VALUES (1, 5000.00)"
db2 "INSERT INTO app.accounts VALUES (2, 3000.00)"
db2 commit
db2 connect reset

Criação dos problemas e respetivo diagnóstico

Vamos gerar uma situação de “lock timeout”. Para isso, iniciamos duas sessões. Uma sessão mantém um lock e a outra sessão tenta aceder à linha que está presa pelo lock até que o timeout ocorra.

cat > /tmp/hold_lock.sh <<'EOF'
#!/bin/bash
db2 connect to DIAGJSON
db2 +c "UPDATE app.accounts SET balance = balance - 100 WHERE id = 1"
sleep 30
db2 commit
db2 connect reset
EOF
chmod +x /tmp/hold_lock.sh

bash /tmp/hold_lock.sh &
LOCK_PID=$!
sleep 3

db2 connect to DIAGJSON
db2 "UPDATE app.accounts SET balance = balance + 100 WHERE id = 1"
kill $LOCK_PID 2>/dev/null
wait $LOCK_PID 2>/dev/null
db2 connect reset

Vamos agora gerar uma situação de deadlock. Para isso, vamos usar duas sessões que processam os dados da mesma tabela em sequências diferentes. Nenhuma delas poderá adquirir o segundo lock, uma vez que a outra sessão já terá a linha pretendida presa.

Para este teste, desativamos o timeout por sessão com CURRENT LOCK TIMEOUT = -1 e reduzimos DLCHKTIME para 1000, para que a deteção do deadlock aconteça antes de o cenário degradar para um timeout.

db2 connect to DIAGJSON
db2 "UPDATE DB CFG FOR DIAGJSON USING DLCHKTIME 1000"
db2 connect reset

cat > /tmp/deadlock_a.sh <<'EOF'
#!/bin/bash
db2 connect to DIAGJSON
db2 "SET CURRENT LOCK TIMEOUT -1"
db2 +c "UPDATE app.accounts SET balance = balance - 100 WHERE id = 1"
sleep 2
db2 +c "UPDATE app.accounts SET balance = balance + 100 WHERE id = 2"
db2 rollback
db2 connect reset
EOF

cat > /tmp/deadlock_b.sh <<'EOF'
#!/bin/bash
db2 connect to DIAGJSON
db2 "SET CURRENT LOCK TIMEOUT -1"
db2 +c "UPDATE app.accounts SET balance = balance - 100 WHERE id = 2"
sleep 2
db2 +c "UPDATE app.accounts SET balance = balance + 100 WHERE id = 1"
db2 rollback
db2 connect reset
EOF

chmod +x /tmp/deadlock_a.sh /tmp/deadlock_b.sh
bash /tmp/deadlock_a.sh &
bash /tmp/deadlock_b.sh &
wait

Depois do teste, reponha o intervalo de deteção padrão se quiser regressar ao comportamento habitual:

db2 connect to DIAGJSON
db2 "UPDATE DB CFG FOR DIAGJSON USING DLCHKTIME 10000"
db2 connect reset

Vamos agora abordar a formatação JSON. O formato JSON do db2diag produz linhas em que cada linha é um objeto JSON independente.

Neste lab, se o timeout por sessão continuar abaixo do intervalo de deteção de deadlocks, o Db2 pode devolver SQL0911N com reason code 68 e registar apenas a contenção como ADM5506W. Por isso o cenário de deadlock abaixo ajusta CURRENT LOCK TIMEOUT e DLCHKTIME antes de repetir o teste.

O ficheiro de schema JSON que define a estrutura esperada. Está presente em ~/sqllib/misc/db2diag.schema.json:

Vamos executar o seguinte comando para inspecioná-lo diretamente:

sed -n '1,80p' ~/sqllib/misc/db2diag.schema.json

Temos agora uma ideia sobre a estrutura do schema antes mesmo de olhar para a saída real do db2diag.

Vamos examinar uma mensagem concreta de lock timeout de forma a comparar com o schema:

db2diag -level Warning -g msg:=ADM5506W -json -V > /tmp/adm5506w.jsonl
head -1 /tmp/adm5506w.jsonl

Vamos agora usar o jq com pretty print para o mesmo efeito:

db2diag -level Warning -g msg:=ADM5506W -json -V | head -1 | jq '.'

Vamos agora listar os nomes dos campos de topo disponíveis na primeira entrada que corresponda a uma mensagem de ADM5506W (lock timeout / contenção):

db2diag -level Warning -g msg:=ADM5506W -json -V |
jq -nr 'first(inputs) | keys_unsorted[]'

Esta abordagem é útil para descobrir rapidamente que campos existem sem depender de examinar visualmente o texto detalhado de uma mensagem.

Vamos agora concretizar um exemplo mais interessante. Efetuamos a filtragem através de parâmetros do db2diag e usamos então jq e column para obter uma formatação tabular perfeita no terminal. O comando column está a ser usado para gerar uma tabela que renderize no terminal com os campos alinhados corretamente. Se direcionar os dados para um ficheiro, pode omitir a utilização do comando column.

O exemplo extrai campos estruturados do JSON e, ao mesmo tempo, faz parsing de partes textuais dentro de message. Isto é mais estável do que tentar fazer o mesmo aplicando grep aos dados de saída do db2diag.

db2diag -level Warning -g msg:=ADM5506W -json -V |
jq -nr '
  def msg: (.message // "" | gsub("[\n ]+"; " "));
  def cap($re): (msg | capture($re).v? // "-");

  ["timestamp","timezone","level","pid","tid","process","instance","member","database","apphdl","appid","uowid","actid","authid","hostname","eduid","eduname","function","probe","event_type","lock_id","event_ts","affected_app","workload","affected_appid","role"],

  (
    inputs
    | [
        (.timestamp // "-"),
        (.timezone // "-"),
        (.level // "-"),
        (.pid // "-"),
        (.tid // "-"),
        (.process // "-"),
        (.instance // "-"),
        (.member // "-"),
        (.database // "-"),
        (.apphdl // "-"),
        (.appid // "-"),
        (.uowid // "-"),
        (.actid // "-"),
        (.authid // "-"),
        (.hostname // "-"),
        (.eduid // "-"),
        (.eduname // "-"),
        (.function // "-"),
        (.probe // "-"),
        cap("type of the event is: \"(?<v>[^\"]+)\""),
        cap("identifier of the lock on which this event happened is: \"(?<v>[^\"]+)\""),
        cap("timestamp of the event is: \"(?<v>[^\"]+)\""),
        cap("affected application is named \"(?<v>[^\"]+)\""),
        cap("workload named \"(?<v>[^\"]+)\""),
        cap("application identifier is: \"(?<v>[^\"]+)\""),
        cap("role that this application plays with respect to this lock is: \"(?<v>[^\"]+)\"")
      ]
  )
  | @tsv
' |
column -t -s $'\t'

Quando for repetir a análise mais do que uma vez, vale a pena guardar as especificações num ficheiro e reutilizá-lo no jq. Vamos criar um ficheiro para as definições. Execute:

mkdir -p ~/db2diag-jq
vi ~/db2diag-jq/adm5506w-locks.jq

Cole agora o seguinte conteúdo no ficheiro:

def msg: (.message // "" | gsub("[\n ]+"; " "));
def cap($re): (msg | capture($re).v? // "-");

["timestamp","timezone","level","pid","tid","process","instance","member","database","apphdl","appid","uowid","actid","authid","hostname","eduid","eduname","function","probe","event_type","lock_id","event_ts","affected_app","workload","affected_appid","role"],

(
  inputs
  | [
      (.timestamp // "-"),
      (.timezone // "-"),
      (.level // "-"),
      (.pid // "-"),
      (.tid // "-"),
      (.process // "-"),
      (.instance // "-"),
      (.member // "-"),
      (.database // "-"),
      (.apphdl // "-"),
      (.appid // "-"),
      (.uowid // "-"),
      (.actid // "-"),
      (.authid // "-"),
      (.hostname // "-"),
      (.eduid // "-"),
      (.eduname // "-"),
      (.function // "-"),
      (.probe // "-"),
      cap("type of the event is: \"(?<v>[^\"]+)\""),
      cap("identifier of the lock on which this event happened is: \"(?<v>[^\"]+)\""),
      cap("timestamp of the event is: \"(?<v>[^\"]+)\""),
      cap("affected application is named \"(?<v>[^\"]+)\""),
      cap("workload named \"(?<v>[^\"]+)\""),
      cap("application identifier is: \"(?<v>[^\"]+)\""),
      cap("role that this application plays with respect to this lock is: \"(?<v>[^\"]+)\"")
    ]
)
| @tsv

Vamos repetir o exemplo anterior mas desta vez usando o ficheiro em vez de fornecer todos os parâmetros na linha de comando. Execute:

db2diag -level Warning -g msg:=ADM5506W -json -V |
jq -nr -f ~/db2diag-jq/adm5506w-locks.jq |
column -t -s $'\t'

6. Considerações finais e resumo

A formatação tradicional do db2diag é adequada para uma inspeção rápida, mas tem algumas limitações. Com db2diag -json, cada evento passa a ser visto como um objeto estruturado, o que facilita:

• Contagens por componente
• Agrupamentos por pid ou tid
• Exportação para TSV/CSV
• Integração com mecanismos de automação e observabilidade

7. Cleanup

Após terminar o lab, execute os seguintes comandos:

db2 connect reset
db2 drop database DIAGJSON

Remova também os ficheiros temporários:

rm -f /tmp/hold_lock.sh /tmp/deadlock_a.sh /tmp/deadlock_b.sh
rm -f ~/db2diag-jq/adm5506w-locks.jq

Documentação IBM útil

Para aprofundar, as referências IBM mais úteis para este tema são:

• Comando db2diag
• Analisar ficheiros db2diag com o comando db2diag
• Definir o nível de captura de erros dos ficheiros de diagnóstico
• Monitorização de eventos de lock e deadlock