Como depurar um aplicativo Spring WebFlux

Depurar um aplicativo Spring WebFlux pode ser uma tarefa desafiadora, especialmente ao lidar com fluxos reativos complexos. Ao contrário dos aplicativos de bloqueio tradicionais, em que o rastreamento de pilha fornece uma indicação clara da causa raiz de um problema, os aplicativos reativos podem ser mais difíceis de depurar. Problemas como código de bloqueio, problemas de simultaneidade e condições de corrida podem causar bugs sutis difíceis de diagnosticar.

Cenário

Ao lidar com um bug nem sempre é um problema relacionado ao código. Pode ser um conjunto de fatores, como refatoração recente, mudanças de equipe, prazos rígidos e assim por diante. Na vida real, é comum acabar solucionando grandes aplicativos feitos por pessoas que saíram da empresa há algum tempo e você acabou de entrar.

Saber um pouco sobre um domínio e tecnologias não vai facilitar sua vida.

No exemplo de código abaixo, eu queria imaginar como seria um código com bugs para uma pessoa que ingressou recentemente em uma equipe.

Considere depurar esse código mais como uma jornada do que como um desafio. A causa raiz pode ser óbvia para aqueles que estão familiarizados com aplicativos reativos. No entanto, algumas práticas abaixo ainda podem ser muito úteis para revisar.

 @GetMapping("/greeting/{firstName}/{lastName}") public Mono<String> greeting(@PathVariable String firstName, @PathVariable String lastName) { return Flux.fromIterable(Arrays.asList(firstName, lastName)) .filter(this::wasWorkingNiceBeforeRefactoring) .transform(this::senselessTransformation) .collect(Collectors.joining()) .map(names -> "Hello, " + names); } private boolean wasWorkingNiceBeforeRefactoring(String aName) { // We don't want to greet with John, sorry return !aName.equals("John"); } private Flux<String> senselessTransformation(Flux<String> flux) { return flux .single() .flux() .subscribeOn(Schedulers.parallel()); }

Portanto, o que esse trecho de código faz é: Ele acrescenta “Hello,“ aos nomes fornecidos como parâmetros.

Seu colega John está lhe dizendo que tudo funciona em seu laptop. Isso é verdade:

 > curl localhost:8080/greeting/John/Doe > Hello, Doe

Mas quando você o executa como curl localhost:8080/greeting/Mick/Jagger , você vê o próximo stacktrace:

 java.lang.IndexOutOfBoundsException: Source emitted more than one item at reactor.core.publisher.MonoSingle$SingleSubscriber.onNext(MonoSingle.java:134) ~[reactor-core-3.5.5.jar:3.5.5] Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: Error has been observed at the following site(s): *__checkpoint ⇢ Handler com.example.demo.controller.GreetingController#greeting(String, String) [DispatcherHandler] *__checkpoint ⇢ HTTP GET "/greeting/Mick/Jagger" [ExceptionHandlingWebHandler] Original Stack Trace: <18 internal lines> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na] (4 internal lines)

Bom, nenhum dos rastreamentos leva a um exemplo de código acima.

Tudo o que revela é que 1) ocorreu no método GreetingController#greeting e 2) o cliente executou um `HTTP GET "/greeting/Mick/Jagger

.doOnError()

A primeira e mais fácil coisa a se tentar é adicionar o retorno de chamada `.doOnError()` ao final da cadeia de saudação.

 @GetMapping("/greeting/{firstName}/{lastName}") public Mono<String> greeting(@PathVariable String firstName, @PathVariable String lastName) { return Flux.fromIterable(Arrays.asList(firstName, lastName)) // <...> .doOnError(e -> logger.error("Error while greeting", e)); }

Boa tentativa, mas os logs não mostram nenhuma melhora.

No entanto, o rastreamento de pilha interno do Reactor:

Aqui estão algumas maneiras pelas quais doOnError pode/não pode ser útil durante a depuração:

1. Registro : você pode usar doOnError para registrar mensagens de erro e fornecer mais contexto sobre o que deu errado em seu fluxo reativo. Isso pode ser especialmente útil ao depurar problemas em um fluxo complexo com muitos operadores.

2. Recuperação : doOnError também pode ser usado para recuperar erros e continuar processando o fluxo. Por exemplo, você pode usar onErrorResume para fornecer um valor ou fluxo de fallback em caso de erro.

3. Depuração : provavelmente doOnError não fornecerá nenhum stacktrace melhor, exceto o que você já viu nos logs. Não confie nele como um bom solucionador de problemas.

   
   

registro()

A próxima parada é substituir a chamada de método doOnError() adicionada anteriormente pela chamada de método log() . Por mais simples que pareça. log() observa todos os sinais de fluxos reativos e os rastreia em logs no nível INFO por padrão.

Vamos ver quais informações adicionais vemos nos logs agora:

Podemos ver quais métodos Reativos foram chamados ( onSubscribe , request e onError ). Além disso, saber de quais threads (pools) esses métodos foram chamados pode ser uma informação muito útil. No entanto, não é relevante para o nosso caso.

log() permite adicionar instruções de log ao seu stream, facilitando o rastreamento do fluxo de dados e o diagnóstico de problemas. Se estivéssemos tendo um fluxo de dados mais complexo com coisas como flatMap, subchains, chamadas de bloqueio, etc., nos beneficiaríamos muito de ter tudo registrado. É uma coisa muito fácil e agradável para o uso diário. No entanto, ainda não sabemos a causa raiz.

Hooks.onOperatorDebug()

A instrução Hooks.onOperatorDebug() informa ao Reactor para ativar o modo de depuração para todos os operadores em fluxos reativos, permitindo mensagens de erro e rastreamentos de pilha mais detalhados.

Segundo a documentação oficial:

A instrução deve ser chamada uma vez por tempo de execução. Um dos melhores lugares seria as classes Configuration ou Main. Para o nosso caso de uso seria:

 public Mono<String> greeting(@PathVariable String firstName, @PathVariable String lastName) { Hooks.onOperatorDebug(); return // <...> }

Adicionando Hooks.onOperatorDebug() podemos finalmente progredir em nossa investigação. Stacktrace é muito mais útil:

E na linha 42 temos a chamada single() .

Não role para cima, o senselessTransformation aparece a seguir:

 private Flux<String> senselessTransformation(Flux<String> flux) { return flux .single() // line 42 .flux() .subscribeOn(Schedulers.parallel()); }

Essa é a causa raiz.

single() emite um item da fonte Flux ou sinaliza IndexOutOfBoundsException para uma fonte com mais de um elemento. Isso significa que o fluxo no método emite mais de 1 item. Subindo na hierarquia de chamadas vemos que originalmente existe um Flux com dois elementos Flux.fromIterable(Arrays.asList(firstName, lastName)) .

O método de filtragem wasWorkingNiceBeforeRefactoring remove um item de um fluxo quando ele é igual a John . Essa é a razão pela qual o código funciona para uma faculdade chamada John. Huh.

Hooks.onOperatorDebug() pode ser particularmente útil ao depurar fluxos reativos complexos, pois fornece informações mais detalhadas sobre como o fluxo está sendo processado. No entanto, ativar o modo de depuração pode afetar o desempenho do seu aplicativo (devido aos rastreamentos de pilha preenchidos), portanto, ele deve ser usado apenas durante o desenvolvimento e a depuração, e não na produção.

pontos de verificação

Para obter quase o mesmo efeito que Hooks.onOperatorDebug() oferece com impacto mínimo no desempenho, existe um operador checkpoint() especial. Ele ativará o modo de depuração para essa seção do fluxo, deixando o restante do fluxo inalterado.

Vamos adicionar dois pontos de verificação após a filtragem e após a transformação:

 public Mono<String> greeting(@PathVariable String firstName, @PathVariable String lastName) { return Flux.fromIterable(Arrays.asList(firstName, lastName)) .filter(this::wasWorkingNiceBeforeRefactoring) /* new */ .checkpoint("After filtering") .transform(this::senselessTransformation) /* new */ .checkpoint("After transformation") .collect(Collectors.joining()) .map(names -> "Hello, " + names); }

Dê uma olhada nos registros:

Essa divisão de pontos de verificação nos informa que o erro foi observado após nosso segundo ponto de verificação descrito como Após a transformação . Isso não significa que o primeiro ponto de verificação não foi alcançado durante a execução. Era, mas o erro começou a aparecer só depois do segundo. É por isso que não vemos Após a filtragem .

Você também pode ver mais dois pontos de verificação mencionados no detalhamento, de DispatcherHandler e ExceptionHandlingWebHandler . Eles foram alcançados após aquele que definimos, até a hierarquia de chamadas.

Além da descrição, você pode forçar o Reactor a gerar um stacktrace para seu ponto de verificação adicionando true como segundo parâmetro ao método checkpoint() . É importante observar que o stacktrace gerado o levará à linha com um ponto de verificação. Ele não preencherá um stacktrace para a exceção original. Portanto, não faz muito sentido porque você pode encontrar facilmente um ponto de verificação fornecendo uma descrição.

Conclusão

Seguindo essas práticas recomendadas, você pode simplificar o processo de depuração e identificar e resolver problemas rapidamente em seu aplicativo Spring WebFlux. Quer você seja um desenvolvedor experiente ou apenas começando na programação reativa, essas dicas ajudarão você a melhorar a qualidade e a confiabilidade do seu código e oferecer melhores experiências aos seus usuários.