Logbook Netty: Support HTTP/2 #961

PascalSchumacher · 2021-02-21T15:39:20Z

Not sure if this is a bug, a feature request or if I am just doing something wrong.

I am using logbook-netty 2.5.0 with reactor-netty-http 1.0.4 which uses netty 4.1.59.Final and everything works fine.

Now I want to enable HTTP/2 in addition to HTTP/1.1:

HttpClient httpClient = HttpClient.create()
        .protocol(HttpProtocol.HTTP11, HttpProtocol.H2).secure()
        .doOnConnected(connection -> connection.addHandlerLast(new LogbookClientHandler(logbook)));
WebClient webClient = webclientBuilder.clone().clientConnector(new ReactorClientHttpConnector(httpClient))
        .apply(oauth2.oauth2Configuration())
        .build();

This results in a logged exception:

WARN [,,,] 11160 --- [ctor-http-nio-2] io.netty.channel.AbstractChannel         : Force-closing a channel whose registration task was not accepted by an event loop: [id: 0x2005f8a5]

java.util.concurrent.RejectedExecutionException: event executor terminated
	at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:926)
	at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:353)
	at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:346)
	at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:828)
	at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:818)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:471)
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:87)
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:81)
	at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:323)
	at io.netty.bootstrap.AbstractBootstrap.register(AbstractBootstrap.java:227)
	at io.netty.resolver.dns.DnsNameResolver.<init>(DnsNameResolver.java:456)
	at io.netty.resolver.dns.DnsNameResolverBuilder.build(DnsNameResolverBuilder.java:476)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newNameResolver(DnsAddressResolverGroup.java:114)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:92)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:77)
	at io.netty.resolver.AddressResolverGroup.getResolver(AddressResolverGroup.java:70)
	at reactor.netty.transport.TransportConnector.doResolveAndConnect(TransportConnector.java:208)
	at reactor.netty.transport.TransportConnector.lambda$connect$2(TransportConnector.java:103)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:125)
	at reactor.netty.transport.TransportConnector$MonoChannelPromise._subscribe(TransportConnector.java:526)
	at reactor.netty.transport.TransportConnector$MonoChannelPromise.lambda$subscribe$0(TransportConnector.java:446)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:834)

and the request failing with:

org.springframework.web.reactive.function.client.WebClientRequestException: failed to create a new resolver; nested exception is java.lang.IllegalStateException: failed to create a new resolver
	at org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.lambda$wrapException$9(ExchangeFunctions.java:137)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
	|_ checkpoint ? Request to POST https://SERVER [DefaultWebClient]
Stack trace:
		at org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.lambda$wrapException$9(ExchangeFunctions.java:137)
		at reactor.core.publisher.MonoErrorSupplied.subscribe(MonoErrorSupplied.java:70)
		at reactor.core.publisher.Mono.subscribe(Mono.java:4046)
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:221)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:221)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:221)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.MonoNext$NextSubscriber.onError(MonoNext.java:93)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onError(MonoFlatMapMany.java:204)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124)
		at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.whenError(FluxRetryWhen.java:224)
		at reactor.core.publisher.FluxRetryWhen$RetryWhenOtherSubscriber.onError(FluxRetryWhen.java:273)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.innerError(FluxConcatMap.java:308)
		at reactor.core.publisher.FluxConcatMap$ConcatMapInner.onError(FluxConcatMap.java:872)
		at reactor.core.publisher.Operators.error(Operators.java:197)
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:52)
		at reactor.core.publisher.Mono.subscribe(Mono.java:4046)
		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.drain(FluxConcatMap.java:448)
		at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.onNext(FluxConcatMap.java:250)
		at reactor.core.publisher.EmitterProcessor.drain(EmitterProcessor.java:491)
		at reactor.core.publisher.EmitterProcessor.tryEmitNext(EmitterProcessor.java:299)
		at reactor.core.publisher.SinkManySerialized.tryEmitNext(SinkManySerialized.java:97)
		at reactor.core.publisher.InternalManySink.emitNext(InternalManySink.java:27)
		at reactor.core.publisher.FluxRetryWhen$RetryWhenMainSubscriber.onError(FluxRetryWhen.java:189)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.MonoCreate$DefaultMonoSink.error(MonoCreate.java:189)
		at reactor.netty.http.client.HttpClientConnect$MonoHttpConnect$ClientTransportSubscriber.onError(HttpClientConnect.java:302)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.MonoCreate$DefaultMonoSink.error(MonoCreate.java:189)
		at reactor.netty.http.client.Http2ConnectionProvider$DisposableAcquire.onError(Http2ConnectionProvider.java:230)
		at reactor.netty.internal.shaded.reactor.pool.AbstractPool$Borrower.fail(AbstractPool.java:427)
		at reactor.netty.internal.shaded.reactor.pool.SimpleDequePool.lambda$drainLoop$5(SimpleDequePool.java:309)
		at reactor.core.publisher.FluxDoOnEach$DoOnEachSubscriber.onError(FluxDoOnEach.java:186)
		at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:132)
		at reactor.core.publisher.MonoCreate$DefaultMonoSink.error(MonoCreate.java:189)
		at reactor.netty.resources.DefaultPooledConnectionProvider$DisposableAcquire.onError(DefaultPooledConnectionProvider.java:166)
		at reactor.netty.internal.shaded.reactor.pool.AbstractPool$Borrower.fail(AbstractPool.java:427)
		at reactor.netty.internal.shaded.reactor.pool.SimpleDequePool.lambda$drainLoop$5(SimpleDequePool.java:309)
		at reactor.core.publisher.FluxDoOnEach$DoOnEachSubscriber.onError(FluxDoOnEach.java:186)
		at reactor.core.publisher.MonoCreate$DefaultMonoSink.error(MonoCreate.java:189)
		at reactor.netty.resources.DefaultPooledConnectionProvider$PooledConnectionAllocator$PooledConnectionInitializer.onError(DefaultPooledConnectionProvider.java:565)
		at org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onError(ScopePassingSpanSubscriber.java:97)
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:192)
		at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:259)
		at reactor.core.publisher.Operators.error(Operators.java:197)
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:52)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64)
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157)
		at reactor.netty.transport.TransportConnector$MonoChannelPromise._subscribe(TransportConnector.java:526)
		at reactor.netty.transport.TransportConnector$MonoChannelPromise.lambda$subscribe$0(TransportConnector.java:446)
		at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
		at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
		at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
		at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
		at java.base/java.lang.Thread.run(Thread.java:834)
	Suppressed: java.lang.Exception: #block terminated with an error
		at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:139)
		at reactor.core.publisher.Mono.block(Mono.java:1727)
		... removed lines to hide information
		at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
		at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779)
		at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
		at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
		at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89)
		at org.springframework.cloud.sleuth.instrument.async.TraceAsyncAspect.traceBackgroundThread(TraceAsyncAspect.java:70)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
		at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
		at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
		at java.base/java.lang.reflect.Method.invoke(Method.java:566)
		at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634)
		at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624)
		at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72)
		at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
		at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
		at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
		at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
		at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750)
		at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at org.springframework.cloud.sleuth.instrument.async.TraceRunnable.run(TraceRunnable.java:68)
		at org.springframework.cloud.sleuth.instrument.async.TraceRunnable.run(TraceRunnable.java:68)
		at XXX.logging.MdcTaskDecorator.lambda$0(MdcTaskDecorator.java:16)
		at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
		at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
		at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.IllegalStateException: failed to create a new resolver
	at io.netty.resolver.AddressResolverGroup.getResolver(AddressResolverGroup.java:72)
	at reactor.netty.transport.TransportConnector.doResolveAndConnect(TransportConnector.java:208)
	at reactor.netty.transport.TransportConnector.lambda$connect$2(TransportConnector.java:103)
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:125)
	at reactor.netty.transport.TransportConnector$MonoChannelPromise._subscribe(TransportConnector.java:526)
	at reactor.netty.transport.TransportConnector$MonoChannelPromise.lambda$subscribe$0(TransportConnector.java:446)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.concurrent.RejectedExecutionException: event executor terminated
	at io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:926)
	at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:353)
	at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:346)
	at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:828)
	at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:818)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.register(AbstractChannel.java:471)
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:87)
	at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:81)
	at io.netty.bootstrap.AbstractBootstrap.initAndRegister(AbstractBootstrap.java:323)
	at io.netty.bootstrap.AbstractBootstrap.register(AbstractBootstrap.java:227)
	at io.netty.resolver.dns.DnsNameResolver.<init>(DnsNameResolver.java:456)
	at io.netty.resolver.dns.DnsNameResolverBuilder.build(DnsNameResolverBuilder.java:476)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newNameResolver(DnsAddressResolverGroup.java:114)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:92)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:77)
	at io.netty.resolver.AddressResolverGroup.getResolver(AddressResolverGroup.java:70)
	... 12 common frames omitted

If I enable only HTTP/2:

HttpClient httpClient = HttpClient.create()
        .protocol(HttpProtocol.H2).secure()
        .doOnConnected(connection -> connection.addHandlerLast(new LogbookClientHandler(logbook)));
WebClient webClient = webclientBuilder.clone().clientConnector(new ReactorClientHttpConnector(httpClient))
        .apply(oauth2.oauth2Configuration())
        .build();

an exception is logged:

WARN [,,,] 11160 --- [ctor-http-nio-2] io.netty.channel.DefaultChannelPipeline  : An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.

java.lang.NullPointerException: null
	at org.zalando.logbook.netty.LogbookClientHandler.channelRead(LogbookClientHandler.java:67)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.http2.Http2MultiplexHandler.channelRead(Http2MultiplexHandler.java:191)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.http2.Http2FrameCodec.onHttp2Frame(Http2FrameCodec.java:707)
	at io.netty.handler.codec.http2.Http2FrameCodec$FrameListener.onSettingsAckRead(Http2FrameCodec.java:672)
	at io.netty.handler.codec.http2.Http2FrameListenerDecorator.onSettingsAckRead(Http2FrameListenerDecorator.java:64)
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsAckRead(DefaultHttp2ConnectionDecoder.java:420)
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:522)
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
	at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
	at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:174)
	at io.netty.handler.codec.http2.DecoratingHttp2ConnectionDecoder.decodeFrame(DecoratingHttp2ConnectionDecoder.java:63)
	at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:378)
	at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:438)
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1533)
	at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1282)
	at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1329)
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:834)

and the request succeds, but the request/response logging by Logbook is missing.

If I disable Logbook by removing the .doOnConnected(connection -> connection.addHandlerLast(new LogbookClientHandler(logbook))); line, both examples work.

The text was updated successfully, but these errors were encountered:

PascalSchumacher · 2021-02-26T22:01:12Z

O.k. this is definitely a feature request. logbook-netty does not support http2.

Here is an minimal way to reproduce this behavior:

<project xmlns="http://maven.apache.org/POM/4.0.0"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>org.test</groupId>
    <artifactId>logbook-netty-http2</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.4.3</version>
        <relativePath /> <!-- lookup parent from repository -->
    </parent>
    <properties>
        <java.version>11</java.version>
    </properties>
    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-webflux</artifactId>
        </dependency>
        <dependency>
            <groupId>org.zalando</groupId>
            <artifactId>logbook-core</artifactId>
            <version>2.5.0</version>
        </dependency>
        <dependency>
            <groupId>org.zalando</groupId>
            <artifactId>logbook-netty</artifactId>
            <version>2.5.0</version>
        </dependency>
    </dependencies>
</project>

public class Main {

    public static void main(String[] args) throws Exception {
        HttpClient httpClient = HttpClient.create()
                .protocol(HttpProtocol.H2).secure()
                .doOnConnected(connection -> connection.addHandlerLast(new LogbookClientHandler(Logbook.create())));
        WebClient webClient = WebClient.builder().clientConnector(new ReactorClientHttpConnector(httpClient))
                .build();

        webClient.get()
                .uri("https://www.google.com")
                .retrieve()
                .bodyToMono(String.class)
                .block(Duration.ofSeconds(5));
    }
}

Edit:
I believe this article could provide some help implementing this feature: https://www.baeldung.com/netty-http2

whiskeysierra · 2021-05-14T12:33:05Z

@PascalSchumacher Are you interested in contributing this?

PascalSchumacher · 2021-05-15T09:36:18Z

I tried to implement it, but did not get very far. Sorry.

PascalSchumacher · 2021-12-05T09:54:35Z

Just wanted to mention: If you use Spring Webflux with Netty, you can use Logbook with HTTP 2 by letting the logbook-spring-webflux module (#1150) handle the logging.

github-actions · 2023-07-31T01:52:39Z

In order to prioritize the support for Logbook, we would like to check whether the old issues are still relevant.
This issue has not been updated for over six months.

Please check if it is still relevant in latest version of the Logbook.
If so, please add a descriptive comment to keep the issue open.
Otherwise, the issue will automatically be closed after a week.

PascalSchumacher · 2023-07-31T17:21:39Z

This issue is still relevant and will become even more relevant with time as more and more traffic is moved from http to http/2.

davidjirovec · 2023-09-26T05:47:58Z

Same issue here

github-actions · 2024-05-13T01:47:37Z

In order to prioritize the support for Logbook, we would like to check whether the old issues are still relevant.
This issue has not been updated for over six months.

Please check if it is still relevant in latest version of the Logbook.
If so, please add a descriptive comment to keep the issue open.
Otherwise, the issue will automatically be closed after a week.

PascalSchumacher · 2024-05-13T06:54:11Z

Adoption of http/2 is already high and increasing, so this issue is still relevant. When using Spring it can be worked-around by using the Logbook Spring integration, but that works at a higher level and therefore will not log some headers. Without Spring there is no workaround.

PascalSchumacher added the Feature label Feb 21, 2021

PascalSchumacher changed the title ~~Logbook Netty: Unable to log HTTP/2 trafic~~ Logbook Netty: Support HTTP/2 Feb 26, 2021

whiskeysierra added the Help Wanted label Sep 23, 2021

github-actions bot added the stale label Jul 31, 2023

github-actions bot removed the stale label Aug 7, 2023

msdousti added the Reactive label Nov 13, 2023

github-actions bot added the stale label May 13, 2024

github-actions bot removed the stale label May 20, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Logbook Netty: Support HTTP/2 #961

Logbook Netty: Support HTTP/2 #961

PascalSchumacher commented Feb 21, 2021

PascalSchumacher commented Feb 26, 2021 •

edited

whiskeysierra commented May 14, 2021

PascalSchumacher commented May 15, 2021

PascalSchumacher commented Dec 5, 2021

github-actions bot commented Jul 31, 2023

PascalSchumacher commented Jul 31, 2023

davidjirovec commented Sep 26, 2023

github-actions bot commented May 13, 2024

PascalSchumacher commented May 13, 2024

Logbook Netty: Support HTTP/2 #961

Logbook Netty: Support HTTP/2 #961

Comments

PascalSchumacher commented Feb 21, 2021

PascalSchumacher commented Feb 26, 2021 • edited

whiskeysierra commented May 14, 2021

PascalSchumacher commented May 15, 2021

PascalSchumacher commented Dec 5, 2021

github-actions bot commented Jul 31, 2023

PascalSchumacher commented Jul 31, 2023

davidjirovec commented Sep 26, 2023

github-actions bot commented May 13, 2024

PascalSchumacher commented May 13, 2024

PascalSchumacher commented Feb 26, 2021 •

edited