MÓDULO 6.2

📜 Debug logging

"Diagnose first, optimize later." A filosofia de logging do OpenHuman: verbose por padrão, prefixos grep-friendly, correlation IDs, runners com tee, mock admin endpoints e tracing do event bus.

7
Tópicos
40
Minutos
Forense
Nível
Prática
Tipo
1

🎙️ Filosofia: verbose por padrão

Não é exagero. O CLAUDE.md formaliza: "Changes lacking diagnosis logging are incomplete." Logging não é cosmético — é parte do contrato de manutenção do PR.

📐 O que sempre logar

  • Entry/exit de funções importantes de domínio
  • Branches de lógica (qual caminho foi tomado e por quê)
  • External calls — request enviada, status de resposta
  • Retries e timeouts — contagem, delay, fim
  • State transitions — estado anterior → novo
  • Errors com contexto suficiente para reproduzir

🚫 NUNCA logar

  • • Secrets (tokens, JWTs, API keys, passwords)
  • • Full PII (emails, telefones, conteúdo de mensagens privadas)
  • • Bodies HTTP completos com dados sensíveis
  • • Memória completa do usuário (apenas IDs e tamanhos)

Redact antes de logar. Se não pode redact, não loga.

Regra
Verbose por padrão
Foco
Flows novos/alterados
Limite
Sem secrets / PII
Status
PR sem log = incompleto
2

🏷️ Prefixos grep-friendly e correlation

Log sem prefixo é palha. Padronize o início da mensagem com tags estáveis e adicione correlation IDs. Em 6 meses, você (ou outro humano) vai precisar reconstruir um fluxo a partir de um arquivo gigantesco.

🔧 Prefixos canônicos

[domain]    — código de domínio (ex.: [memory], [skills])
[rpc]       — chamadas JSON-RPC entrando/saindo
[ui-flow]   — flows multi-step de UI
[bus]       — event bus publish/subscribe
[transport] — socket.io, tunnel, HTTP local

🔬 Exemplo com correlation

[rpc] req_id=a1b2 method=openhuman.memory_list status=start
[memory] req_id=a1b2 entity=user:42 fetching limit=50
[memory] req_id=a1b2 entity=user:42 result_count=37 elapsed=42ms
[rpc] req_id=a1b2 method=openhuman.memory_list status=ok elapsed=44ms

grep "req_id=a1b2" reconstrói o fluxo inteiro — RPC → domain → resposta — em ordem temporal.

✓ Bom log

[skills] op=install slug=foo
  req_id=a1b2 version=1.2.0
  source=manifest result=ok
  elapsed=120ms

✗ Log inútil

installed
ok
done
finished
something happened
Tag
[domain] no início
ID
req_id correlation
Campos
key=value pareados
Reconstrução
grep + sort = trace
3

🦀 Rust: tracing & log

No core, prefira tracing sobre log — ele dá spans correlacionados e fields estruturados. Nível debug para flows normais, trace para detalhe muito fino.

📋 Receita básica

use tracing::{debug, info, instrument};

#[instrument(skip(store), fields(entity_id = %entity.id))]
pub async fn fetch_memory(store: &Store, entity: &Entity, limit: u32) -> Result<Vec<Memory>> {
    debug!(limit, "[memory] start fetch");
    let items = store.list(entity, limit).await?;
    debug!(count = items.len(), "[memory] fetched");
    Ok(items)
}

#[instrument] abre um span automaticamente — todos os logs internos herdam entity_id.

⚙️ Controle por env

# Tudo openhuman no nível debug
RUST_LOG=openhuman=debug pnpm dev:app

# Só o domínio memory + trace
RUST_LOG=openhuman::memory=trace,openhuman=info pnpm dev:app

# Silenciar dependências ruidosas
RUST_LOG=openhuman=debug,hyper=warn,sqlx=warn pnpm dev:app

💡 Macete

Use % para Display e ? para Debug nos fields. Ex.: fields(id = %user.id, opts = ?config). Sem isso o tracing serializa com Debug por padrão — verboso demais.

Crate
tracing > log
Macro
#[instrument]
Env
RUST_LOG=openhuman=debug
Nível
debug → trace
4

🌐 JS: debug namespaced

No app, evite console.log() direto. Use a lib debug com namespaces — ativável seletivamente em runtime via localStorage, invisível em produção.

📋 Setup

// app/src/services/chatService.ts
import debug from 'debug';
const log = debug('openhuman:chat');

export async function sendMessage(text: string) {
  log('[ui-flow] sending msg len=%d', text.length);
  // ...
  log('[ui-flow] msg ok id=%s', result.id);
}

🎛️ Ativando no DevTools

// Console do navegador:
localStorage.debug = 'openhuman:*'      // tudo
localStorage.debug = 'openhuman:chat'   // só chat
localStorage.debug = 'openhuman:*,-openhuman:noise'  // exceto noise
// Recarregue a página

✓ Fazer

  • Namespaces por módulo
  • Detalhe rico em %o objects
  • Cores automáticas por namespace

✗ Evitar

  • console.log nu em prod
  • Logging sem namespace
  • Logar tokens / payloads sensíveis
Lib
debug com namespaces
Storage
localStorage.debug
Wildcard
openhuman:*
Banido
console.log em prod
5

📦 scripts/debug — bounded output + tee

Wrappers prontos sobre Vitest, WDIO e cargo. Stdout vira summary (cabe na janela do agente), enquanto o log completo é teed para target/debug-logs/.

📋 Comandos essenciais

# Vitest
pnpm debug unit                                # full suite
pnpm debug unit src/components/Foo.test.tsx    # arquivo específico
pnpm debug unit Foo -t "renders empty"         # filtro
pnpm debug unit Foo --verbose                  # stream raw também

# WDIO
pnpm debug e2e test/e2e/specs/smoke.spec.ts smoke

# cargo
pnpm debug rust json_rpc_e2e

# Inspecionar logs salvos
pnpm debug logs                # listar 50 mais recentes
pnpm debug logs last           # último (400 linhas)
pnpm debug logs unit           # último com prefix unit
pnpm debug logs last --tail 100

💡 Por que isso importa

Sem bounded output, um vitest --reporter verbose pode despejar 50k linhas e estourar contexto de um agente. Com pnpm debug, você vê o resumo e busca detalhes só quando precisa.

Entry
pnpm debug
Modos
unit / e2e / rust
Logs
target/debug-logs/
Stream raw
--verbose
6

🔍 Mock API admin — inspeção sem print

O mock backend (scripts/mock-api-server.mjs) expõe endpoints administrativos para inspecionar requests recebidas, resetar estado e injetar comportamentos. Substitui prints durante testes — você lê direto o que o app mandou.

🔧 Endpoints

Endpoint Uso
GET /__admin/healthMock está vivo
GET /__admin/requestsLista todas as requests recebidas
POST /__admin/resetLimpa estado entre testes
POST /__admin/behaviorInjeta resposta custom (4xx, delay, etc.)

🧪 Uso típico no teste

// beforeEach
await fetch('http://localhost:4567/__admin/reset', { method: 'POST' });

// ... ação do teste ...

// Verificar o que o app mandou
const res = await fetch('http://localhost:4567/__admin/requests');
const requests = await res.json();
expect(requests).toContainEqual(expect.objectContaining({
  method: 'POST',
  path: '/v1/messages'
}));
Script
pnpm mock:api
Inspect
/__admin/requests
Reset
/__admin/reset
Inject
/__admin/behavior
7

📡 Event bus tracing subscriber

O EventBus do core vem com um TracingSubscriber embutido — basta registrar e todos os DomainEvent publicados aparecem no log com domain + payload resumido. Você não precisa instrumentar manualmente.

📋 Como ligar

use crate::core::event_bus::{init_global, subscribe_global, TracingSubscriber};

// No bootstrap do core:
init_global(1024);
subscribe_global(Box::new(TracingSubscriber::default()));

// Agora todo publish_global(event) loga:
// [bus] domain=memory event=MemoryUpserted entity_id=42
// [bus] domain=cron event=CronFired job_id=daily-digest
// [bus] domain=channel event=MessageReceived channel=slack

🎯 Subscriber customizado

struct MyDebugSub;

#[async_trait]
impl EventHandler for MyDebugSub {
    fn name(&self) -> &str { "debug::my-flow" }
    fn domains(&self) -> Option<&[&str]> { Some(&["memory", "skills"]) }

    async fn handle(&self, event: DomainEvent) {
        tracing::debug!(?event, "[my-flow] got event");
    }
}

domains() filtra — só recebe events das categorias listadas. name() aparece no log do próprio subscriber para identificar.

💡 Quando usar

  • • Debugar ordem de eventos cross-domain (ex.: cron disparou antes do channel processar?)
  • • Validar que um novo subscriber está mesmo recebendo o event esperado
  • • Profiling de quem publica demais (subscriber barato que conta por domain)
Built-in
TracingSubscriber
API
subscribe_global
Filtro
domains() opcional
RAII
SubscriptionHandle

🧰 Resumo do Módulo

Verbose por padrão — sem log de diagnose, PR é incompleto.
Prefixos + correlation IDs — log que dá grep e reconstrói flows.
Rust tracing#[instrument] + fields estruturados + RUST_LOG.
JS debug namespacedlocalStorage.debug = 'openhuman:*'.
scripts/debug — output truncado + tee para target/debug-logs/.
Mock API admin/__admin/requests substitui prints.
Event bus tracingTracingSubscriber revela ordem de events.

Próximo Módulo:

6.3 — 💎 Dicas avançadas: i18n strict, sem dynamic imports, controllers, webview zero-injection.