Estabilizando o Keycloak em escala: Ferramentas para depuração e investigação

Nós da Smallpdf introduzimos o Keycloak para autenticação no verão de 2021. Como muitas das novas implementações, não foi um processo tranquilo e levou muito mais tempo do que o esperado. Para ajudá-lo a evitar um longo processo para solucionar problemas, o engenheiro de software da equipe do Smallpdf, Silvan Jegen, faz um mergulho profundo nos problemas encontrados e nas técnicas usadas para investigá-los e depurá-los. Esperamos que isso te ajude no seu processo de implementação!

Problemas de estabilidade

 

Nossa configuração inicial incluía várias instâncias do Keycloak, cada uma com um cache Infinispan incorporado. Ao colocar essas instâncias em produção, ocorreram problemas de estabilidade devido à exaustão da memória do nó, o que causou reinicializações e perda de sessões de usuário, desconectando os usuários efetivamente.

Depois de vários meses de experimentos sobre como resolver esses problemas de estabilidade, tentamos diferentes combinações de caches Infinispan incorporados e externos com diferentes opções. Por um tempo, usamos a opção SIFS em um cache Infinispan externalizado, mas, após cerca de duas semanas, essa configuração resultou em uma interrupção.

No final, optamos por uma configuração com várias instâncias do Keycloak, todas conectadas a um cluster externo do Infinispan. Depois de configurarmos nós suficientes para sustentar a carga de produção tanto no Keycloak quanto no Infinispan, finalmente conseguimos um sistema de produção estável.

Vamos dar uma olhada em como chegamos à configuração final, passo a passo.

Teste de carregamento

 

Nossa experiência com Keycloak + Infinispan com RocksDB nos mostrou que nossa carga de trabalho de produção não estava tão próxima das condições de teste de carga quanto pensávamos. Como queríamos evitar que essas interrupções se repetissem, optamos por fazer mais uso dos testes de carga.

A ferramenta que utilizamos para isso foi o "k6". Essa ferramenta nos permitiu gerar solicitações com um rigoroso controle (graças ao script em JavaScript). Também pudemos personalizar a forma como as solicitações eram enviadas (ou seja, frequência, duração etc.). Dessa forma, pudemos analisar o problema de uma forma mais detalhada.

Como precisávamos fazer a transição de um sistema de autenticação legado, tivemos que enviar solicitações de concessão direta à nossa instância do Keycloak. Esse processo imitaria a criação de sessões de cluster. . Para fazer isso, usamos o seguinte script:

Para executar esse script com "k6" por uma hora, usando 16 conexões TCP para enviar solicitações em paralelo, você pode usar a seguinte linha de comando:

Observação: ao usar esse script, você cria várias sessões de concessão direta para a mesma conta de usuário. Isso pode ou não ser o que você realmente deseja testar na sua própria instância do Keycloak.

Resolvendo o problema

 

Conseguimos verificar se nossa carga de produção poderia ser suportada usando o "k6" para carregar sessões e verificando as métricas e os logs do JVM que coletamos.

Carregar sessões no Infinispan com "k6" diretamente em vez de enviá-las ao Keycloak acabou não refletindo com precisão o que aconteceria quando colocássemos o Keycloak junto com o Infinispan na produção. Portanto, para conseguir os melhores resultados, recomendamos carregar as sessões enviando solicitações ao Keycloak usando o script acima, em vez de carregá-las diretamente no Infinispan, embora isso seja mais rápido.

Sessões perdidas

 

Quando nossos clusters Keycloak e Infinispan ficaram estáveis, esperávamos que a contagem de erros de token de atualização que estávamos observando anteriormente diminuísse. De fato, tivemos menos erros, mas ainda eram muitos. Milhares de usuários eram desconectados diariamente quando tentavam atualizar seus tokens de acesso.

Conseguindo mais informações

 

Voltamos à prancheta de desenho. Para depurar esse problema, primeiro consultamos o registro de eventos fornecido com o Keycloak. No entanto, o nível de registro padrão definido no sistema era muito alto para conseguir as informações nas quais estávamos interessados. Portanto, para ter registros mais detalhados, definimos o nível como "DEBUG". No entanto, esteja ciente de que esse nível cria uma grande quantidade de dados. Se você estiver salvando esses logs de eventos no banco de dados relacional do Keycloak e tiver um tráfego considerável, isso provavelmente causará alguns problemas.

Os registros obtidos dessa forma ainda não continham os detalhes necessários para identificar a origem desses erros de token de atualização (Refresh Token Errors). Acabamos corrigindo o código da nossa instância do Keycloak para adicionar mais detalhes do que os erros genéricos fornecidos, bem como os IDs de sessão. Esse último nos permitiu associar mais facilmente os Refresh Token Errors aos eventos de "Login" correspondentes.

Com essas informações adicionais em mãos, rapidamente soubemos onde procurar: a grande maioria dos nossos erros de token de atualização era devido a erros "session_not_found" (sessão não encontrada). Isso indicava que o Keycloak não estava encontrando as sessões dos nossos usuários depois de algum tempo, embora o tempo até a perda da sessão parecesse variar muito.

Criação de uma configuração controlada

 

A próxima etapa foi reproduzir o problema em um ambiente controlado. Descobrimos que a melhor maneira de fazer isso era criar uma configuração local do Keycloak+Infinispan para a qual pudéssemos enviar solicitações usando o Postman. Usando essa configuração local, pudemos aumentar o nível de registro para "TRACE" sem nos afogar, já que não havia tráfego de produção com o qual nos preocupar.

O nível de depuração "TRACE" nos permitiu ver que as novas sessões foram inicialmente recuperadas com sucesso do Infinispan após a criação. Com o tempo, no entanto, o Keycloak tentava recuperar uma sessão no lado do Infinispan. Sem motivo aparente, isso fazia com que a sessão desaparecesse.

Descobriu-se que o fato de retirar e recuperar uma sessão do disco duas vezes seguidas fazia com que a sessão não fosse encontrada no momento da próxima solicitação de token de atualização. Não se sabe por que isso acontece. Ainda não descobrimos o motivo. O desaparecimento da sessão era a fonte dos erros de token de atualização que estávamos observando no nosso ambiente de produção.

Então, o que aprendemos?

 

A depuração do Keycloak é complexa, especialmente se você estiver executando-o com um cluster Infinispan externalizado. Talvez não seja suficiente trabalhar apenas com as métricas da JVM e os logs fornecidos.

Nesse caso, uma configuração local é um ótimo método para reproduzir o problema que você está tendo, mesmo que seja necessário corrigir o Keycloak para obter os dados necessários para depurar o problema.

Não se esqueça também de fazer alguns testes de carregamento adequados para as alterações que estiver fazendo na configuração do Keycloak. Com base na nossa experiência, isso provavelmente lhe poupará alguns problemas na produção!

Com agradecimentos especiais a Sam Smith e Zhandos Zhylkaidar por contribuir com este artigo.

Gostou desta postagem? Fique atento a mais informações, insights e dicas dos engenheiros do Smallpdf em breve no blog.

Traduzido e adaptado para o português por Ariane.