Como diagnosticar queda de multiplexing no RDS Proxy com CloudWatch Logs Insights

Quem administra RDS Proxy na frente de um Aurora PostgreSQL ou de um RDS for PostgreSQL já viu o sintoma: DatabaseConnections sobe, a economia de pool que justificou colocar o proxy ali some, e o cluster volta a sofrer pressão de conexão como se o proxy não existisse. A AWS publicou a segunda parte de uma série no Database Blog dedicada exatamente a isso: depois de explicar, na Parte 1, as três causas clássicas (connection pinning, fragmentação de pool e transações não commitadas), a Parte 2 mostra como ir além da métrica quando ela não basta.

O problema que o post ataca é concreto. DatabaseConnectionsCurrentlySessionPinned ou a razão entre DatabaseConnections e ClientConnections dizem que algo piorou, mas são amostradas uma vez por minuto, as três causas costumam coexistir no mesmo momento, e nenhuma delas aponta qual ApplicationName, qual usuário de banco ou qual job de Amazon EMR está pinando conexão. Para isso, a AWS recomenda trocar o standard proxy logging por enhanced logging e rodar CloudWatch Logs Insights.

Ligar o enhanced logging sem incendiar o orçamento

Enhanced logging faz o RDS Proxy emitir mensagens DEBUG no mesmo log group (/aws/rds/proxy/<proxy-name>) mostrando o ciclo completo de borrow/release: qual cliente pegou qual conexão de backend e quando ela voltou ao pool. Sem isso, a Parte 1 só confirma QUE existe pinning ou fragmentação; é o enhanced logging que mostra QUEM está causando.

# Ativar durante o diagnóstico
aws rds modify-db-proxy --db-proxy-name my-proxy --debug-logging

# Desativar depois da investigação (tem overhead)
aws rds modify-db-proxy --db-proxy-name my-proxy --no-debug-logging

Três cuidados que o post destaca merecem atenção de quem vai propor isso em produção:

• O RDS Proxy desliga enhanced logging sozinho 24 horas depois de ativado, mas não dá para contar com esse timeout: desligue manualmente assim que terminar a investigação.
• O log registra o texto das SQL statements enviadas pelo proxy, o que pode incluir dado sensível. Restrinja o acesso ao log group a quem realmente precisa e configure um retention period curto.
• O volume de DEBUG por borrow/release é alto em proxy com tráfego real, o que aumenta ingestão e armazenamento no CloudWatch Logs e pode adicionar overhead ao próprio proxy. A AWS é explícita: ative só para diagnóstico, desative depois.

Para rodar as queries também é preciso logs:StartQuery, logs:GetQueryResults e logs:DescribeLogGroups via IAM, além de log_connections=on no DB Parameter Group (ou DB Cluster Parameter Group, no caso de Aurora) para que o PostgreSQL registre application_name nas entradas connection authorized.

As queries que mostram o borrow/release de cada conexão

A query central do post é um resumo de reuso por conexão de backend, usando o campo dbConnection extraído da mensagem:

fields @timestamp, @message
| parse @message /[dbConnection=(?<dbid>\d+)]/
| filter ispresent(dbid)
| stats
  min(if(strcontains(@message, "A TCP connection was established from the proxy"), @timestamp, "")) as established_at,
  min(if(strcontains(@message, "The database connection closed"), @timestamp, "")) as closed_at,
  sum(strcontains(@message, "borrowed the database connection")) as borrows,
  sum(strcontains(@message, "being released to the connection pool")) as releases,
  sum(strcontains(@message, "was pinned to the database connection")) as pinned
by dbid
| sort established_at desc

O contraste entre os dois estados, no mesmo teste descrito no post, é didático. Com multiplexing saudável, 60 conexões de backend sustentaram o workload, com 12 a 117 borrows por conexão e zero pin. Com pinning ativo, o pool precisou de 154 conexões (quase três vezes mais), cada uma com 8 borrows e 8 pins: ou seja, cada conexão foi usada uma vez e travada, sem reuso.

Para investigar uma conexão específica, a segunda query isola o dbConnection e ordena por tempo, revelando o ciclo de vida completo: no exemplo do post, uma única conexão (dbConnection=4020092827) foi emprestada e devolvida 153 vezes por clientes diferentes durante um teste saudável, o retrato exato do que multiplexing eficiente deveria parecer.

Achando o aplicativo culpado: correlação com o log do PostgreSQL

Quando a pergunta não é "existe pinning?" mas "qual aplicação está causando pinning?", o post descreve um procedimento de correlação entre os logs do proxy e os logs do PostgreSQL:

1. Rodar a query de resumo de reuso para ter borrows, releases e pins por dbConnection.
2. Filtrar o log do proxy por TCP connection was established para extrair o IP:porta de saída do proxy associado a cada dbConnection.
3. Filtrar o log do PostgreSQL por connection authorized, que traz IP:porta do cliente (igual ao IP:porta de saída do proxy), database user, database name e application_name.
4. Cruzar os dois resultados pelo IP:porta.

O resultado final tem duas visões: detalhe por conexão (borrows, releases, pins, usuário, ApplicationName) e resumo por usuário mais ApplicationName, somando conexões, borrows e pins por partição de pool. Um ambiente fragmentado aparece como muitas conexões com poucos borrows espalhadas em várias combinações de usuário e ApplicationName; um ambiente pinado mostra contagem de pin igual à de borrow, com borrow baixo.

O próprio post avisa que esse join por IP:porta é best-effort, não uma chave garantida: portas são reaproveitadas quando conexões fecham e reabrem, então a correlação só é confiável dentro da mesma janela de tempo e exige relógios sincronizados entre as duas fontes de log. Trate o resultado como evidência forte de qual usuário e ApplicationName pertence a uma conexão, não como mapeamento exato.

Como fica a métrica quando está tudo bem

O post fecha o quadro de referência com os números do teste saudável: DatabaseConnections em torno de 59, sustentando 325 ClientConnections simultâneos, uma razão de aproximadamente 0,18. Como regra prática, razão abaixo de 0,2 indica multiplexing saudável (5:1 ou melhor); razão de 1,0 significa que cada cliente tem sua própria conexão de backend, ou seja, nenhum multiplexing de fato.

Dois alarmes para pegar regressão antes do incidente

Depois de corrigir pinning, fragmentação e transação aberta, o ganho se perde de novo com facilidade: deploy de driver novo, mudança de framework ou um job de EMR com parâmetro de sessão diferente bastam. O post propõe dois alarmes no CloudWatch que cobrem esse cenário sem exigir enhanced logging ligado o tempo todo.

O primeiro observa DatabaseConnectionsCurrentlySessionPinned acima de um baseline próprio (nunca zero, porque alguma ferramenta administrativa pina por natureza), por cinco pontos consecutivos de um minuto:

aws cloudwatch put-metric-alarm \
--alarm-name "rds-proxy-pinning-detected" \
--namespace "AWS/RDS" \
--metric-name "DatabaseConnectionsCurrentlySessionPinned" \
--dimensions Name=ProxyName,Value=my-proxy Name=TargetGroup,Value=default \
--statistic Sum --period 60 --evaluation-periods 5 --threshold 10 \
--comparison-operator GreaterThanThreshold --treat-missing-data notBreaching

O segundo usa metric math para acompanhar a razão backend/cliente diretamente, com uma trava para não disparar em baixo tráfego: IF(cc > 50, dc / cc, 0), onde o piso de 50 clientes evita falso positivo quando MaxIdleConnectionsPercent mantém conexões ociosas no pool em horário de baixo uso. O post sugere limiar inicial de 0,5, ajustável conforme a razão que o próprio workload normalmente atinge.

O que isso custa e quando não vale a pena

Enhanced logging não é algo para deixar ligado permanentemente: o volume DEBUG por borrow/release em proxy de produção é alto, cobra ingestão e armazenamento no CloudWatch Logs por GB, e adiciona overhead ao proxy. A recomendação da AWS é tratá-lo como ferramenta de diagnóstico pontual, com retention curto e acesso restrito ao log group, não como telemetria contínua.

O mesmo cuidado vale para o Logs Insights: ele cobra por volume de dado escaneado e tem um teto de escaneamento por consulta, então em proxy de alto volume o retorno é melhor restringindo a janela de tempo e colocando filter cedo na query, antes de qualquer stats ou parse custoso. Para quem só precisa confirmar se o multiplexing está saudável, a query de resumo de reuso sozinha já responde a maioria das perguntas; a correlação completa com os logs do PostgreSQL só compensa quando o objetivo é apontar o dedo para uma aplicação ou equipe específica.

Fonte: AWS Database Blog