Declarative http client calls fails on any https url's when built on native image with exception: io.micronaut.http.client.exceptions.HttpClientException: Connect Error: connection timed out
There is no such problem with http urls.
I am providing link to example application build from template mn create-app my-app --features aws-api-gateway-graal and following extensions:
ExampleController extended to call https API by using declarative http clientnative-image options -H:EnableURLProtocols=http,https --enable-all-security-services -H:+JNImn create-app my-app --features aws-api-gateway-graal (found in docs under Custom GraalVM Native Runtimes in https://micronaut-projects.github.io/micronaut-aws/latest/guide/#customRuntimes)ExampleController to use declarative http client for calling any https API/URLNo error should happen
ExampleController https call results in error:
io.micronaut.http.client.exceptions.HttpClientException: Connect Error: connection timed out: www.boredapi.com/34.237.203.145:443
at io.micronaut.http.client.DefaultHttpClient.lambda$null$27(DefaultHttpClient.java:1048)
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577)
at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:570)
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:549)
at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490)
at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615)
at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:608)
at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:117)
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:263)
at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510)
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
Caused by: io.netty.channel.ConnectTimeoutException: connection timed out: www.boredapi.com/34.237.203.145:443
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261)
... 13 more
Thanks for reporting the issue. We're aware of it and we're working with the Amazon team to fix it. Hopefully we will have a solution soon.
Good to know. Thanks!
I've been trying to deploy a Micronaut app that uses the HttpClient to call an external HTTPS API as a Graal app in Lambda for a while. I've done a lot of tests and I still not sure where is the problem or who is the culprit.
I've been doing a lot of tests and trying different things and I still don't know where is the problem or who is the culprit. I used Graal 19.2.1 in all the tests but then I tried with Graal 20.0.0-dev compiled from source code. For one time it worked, but then, after a redeploy it didn't work anymore.
One final thing I've tried is to deploy the Micronaut application but in create another action in the controller that doesn't use HTTP Client (https://github.com/ilopmar/chuck-norris-facts-mn-graal-function/commit/560a7b708307b2754167dc9f97c58157bed27980):
@Get("/joke2")
public Fact getFact2() throws IOException {
System.out.println("============================ IcndbController.getFact2 ============================");
URL url = new URL("https://api.icndb.com/jokes/random/");
HttpURLConnection con = (HttpURLConnection) url.openConnection();
con.setRequestMethod("GET");
con.setRequestProperty("Content-Type", "application/json");
con.setConnectTimeout(10000);
con.setReadTimeout(10000);
con.setInstanceFollowRedirects(true);
int status = con.getResponseCode();
System.out.println(status);
BufferedReader in = new BufferedReader(
new InputStreamReader(con.getInputStream()));
String inputLine;
StringBuffer content = new StringBuffer();
while ((inputLine = in.readLine()) != null) {
content.append(inputLine);
}
in.close();
System.out.println(content.toString());
return mapper.readValue(content.toString(), Fact.class);
}
That works, so the issue is something related to Netty SSL and Graal (or Micronaut), but not sure exactly where it is. It works in a Micronaut app compiled as native-image, it works deployed to sam local, but it fails when deployed to Lambda...Is it a Netty SSL issue in GraalVM? Is it a Netty issue because of how we use it in Micronaut? Is it something related to Netty and AWS Lambda? And also why did it work with the dev version once and now it doesn't work anymore?...
I'm attaching 4 log files:
getFact2) getFact). New curl request.getFact). New curl request.In all the logs (even the one that works) there are errors regarding Netty missing methods, but I'm not really sure if this is the root cause or just a "side effect" of the timeout error.
The following log aws-lambda-ok-20.0.0.log is for the only execution that worked with Graal 20.0.0-dev. Interesting lines:
Between all those lines there are a lot of Netty and Micronaut HttpClient method missing:
$ grep "missing method" aws-lambda-ok-20.0.0.log
2019-11-15T07:33:45.526Z [2019-11-15 08:33:45.525] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.526Z [2019-11-15 08:33:45.526] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.545Z [2019-11-15 08:33:45.526] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.545Z [2019-11-15 08:33:45.526] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.545Z [2019-11-15 08:33:45.545] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.545Z [2019-11-15 08:33:45.545] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.565Z [2019-11-15 08:33:45.545] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.565Z [2019-11-15 08:33:45.565] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.565Z [2019-11-15 08:33:45.565] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method bind, assume we can not skip execution
2019-11-15T07:33:45.565Z [2019-11-15 08:33:45.565] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method connect, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.565] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method disconnect, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.565] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method close, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method deregister, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method read, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method write, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method flush, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.585Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.586Z [2019-11-15 08:33:45.585] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.586Z [2019-11-15 08:33:45.586] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.586Z [2019-11-15 08:33:45.586] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.586Z [2019-11-15 08:33:45.586] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.586Z [2019-11-15 08:33:45.586] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.605Z [2019-11-15 08:33:45.586] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.605Z [2019-11-15 08:33:45.605] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.605Z [2019-11-15 08:33:45.605] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.605Z [2019-11-15 08:33:45.605] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.605] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.625Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.626Z [2019-11-15 08:33:45.625] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.626Z [2019-11-15 08:33:45.626] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.626Z [2019-11-15 08:33:45.626] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.626Z [2019-11-15 08:33:45.626] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.626] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method bind, assume we can not skip execution
2019-11-15T07:33:45.645Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method connect, assume we can not skip execution
2019-11-15T07:33:45.646Z [2019-11-15 08:33:45.645] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method disconnect, assume we can not skip execution
2019-11-15T07:33:45.646Z [2019-11-15 08:33:45.646] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method close, assume we can not skip execution
2019-11-15T07:33:45.646Z [2019-11-15 08:33:45.646] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method deregister, assume we can not skip execution
2019-11-15T07:33:45.665Z [2019-11-15 08:33:45.665] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method read, assume we can not skip execution
2019-11-15T07:33:45.665Z [2019-11-15 08:33:45.665] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method write, assume we can not skip execution
2019-11-15T07:33:45.665Z [2019-11-15 08:33:45.665] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method flush, assume we can not skip execution
2019-11-15T07:33:45.665Z [2019-11-15 08:33:45.665] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.685Z [2019-11-15 08:33:45.667] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.745Z [2019-11-15 08:33:45.685] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.765Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.765Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.765Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.765Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.765Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.785Z [2019-11-15 08:33:45.765] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.785Z [2019-11-15 08:33:45.785] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.785Z [2019-11-15 08:33:45.785] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.785Z [2019-11-15 08:33:45.785] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.785Z [2019-11-15 08:33:45.785] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.786Z [2019-11-15 08:33:45.785] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.786Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.786Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.786Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method bind, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.786] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method connect, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.805] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method disconnect, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.805] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method close, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.805] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method deregister, assume we can not skip execution
2019-11-15T07:33:45.805Z [2019-11-15 08:33:45.805] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method read, assume we can not skip execution
2019-11-15T07:33:45.806Z [2019-11-15 08:33:45.805] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method write, assume we can not skip execution
2019-11-15T07:33:45.806Z [2019-11-15 08:33:45.806] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method flush, assume we can not skip execution
2019-11-15T07:33:45.806Z [2019-11-15 08:33:45.806] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.timeout.ReadTimeoutHandler missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.951] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.951] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.965Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method bind, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.965] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method connect, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method disconnect, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method close, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method deregister, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method read, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method write, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method flush, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.966Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.966] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.967Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.967] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method bind, assume we can not skip execution
2019-11-15T07:33:45.968Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method connect, assume we can not skip execution
2019-11-15T07:33:45.969Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method disconnect, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:45.968] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method close, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:46.025] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method deregister, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:46.025] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method read, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:46.025] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method write, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:46.025] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method flush, assume we can not skip execution
2019-11-15T07:33:46.025Z [2019-11-15 08:33:46.025] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.045Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.046Z [2019-11-15 08:33:46.045] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.046Z [2019-11-15 08:33:46.046] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.046Z [2019-11-15 08:33:46.046] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.066Z [2019-11-15 08:33:46.065] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.066Z [2019-11-15 08:33:46.065] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.085Z [2019-11-15 08:33:46.085] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method bind, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method connect, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method disconnect, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method close, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method deregister, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method read, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method write, assume we can not skip execution
2019-11-15T07:33:46.105Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method flush, assume we can not skip execution
2019-11-15T07:33:46.106Z [2019-11-15 08:33:46.105] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpClientCodec missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.106Z [2019-11-15 08:33:46.106] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.106Z [2019-11-15 08:33:46.106] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.106Z [2019-11-15 08:33:46.106] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.106Z [2019-11-15 08:33:46.106] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.106] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.netty.handler.codec.http.HttpContentDecompressor missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.125Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.126Z [2019-11-15 08:33:46.125] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.126Z [2019-11-15 08:33:46.126] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.126Z [2019-11-15 08:33:46.126] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.126Z [2019-11-15 08:33:46.126] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.126Z [2019-11-15 08:33:46.126] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.145Z [2019-11-15 08:33:46.126] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$1 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.145Z [2019-11-15 08:33:46.145] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.145Z [2019-11-15 08:33:46.145] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.145Z [2019-11-15 08:33:46.145] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.145] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method bind, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method connect, assume we can not skip execution
2019-11-15T07:33:46.225Z [2019-11-15 08:33:46.225] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method disconnect, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.226] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method close, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.245] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method deregister, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.245] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method read, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.245] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method write, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.245] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method flush, assume we can not skip execution
2019-11-15T07:33:46.245Z [2019-11-15 08:33:46.245] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$HttpClientInitializer$4 missing method exceptionCaught, assume we can not skip execution
2019-11-15T07:33:46.246Z [2019-11-15 08:33:46.246] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRegistered, assume we can not skip execution
2019-11-15T07:33:46.246Z [2019-11-15 08:33:46.246] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelUnregistered, assume we can not skip execution
2019-11-15T07:33:46.246Z [2019-11-15 08:33:46.246] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelActive, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.246] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelInactive, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRead, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelReadComplete, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelWritabilityChanged, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method userEventTriggered, assume we can not skip execution
2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method exceptionCaught, assume we can not skip execution
Maybe the actual root cause is because of 2019-11-15T07:33:46.265Z [2019-11-15 08:33:46.265] <request-id-not-set-by-lambda-runtime> DEBUG i.n.c.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method exceptionCaught, assume we can not skip execution and it's something we need to fix on Micronaut.
I've set the log level to trace for both Netty and Micronaut and I see the same errors in the standalone application. It works, but the errors are still there log-standalone.txt.
@graemerocher do you think it's worth it opening a issue in GraalVM tracker or is it better to take a look first in Micronaut? I ask because the following errors are because of missing method in Micronaut DefaultHttpClient, although the class is io.netty.channel.ChannelHandlerMask:
15:10:28.271 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRegistered, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelUnregistered, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelActive, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelInactive, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelRead, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelReadComplete, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method channelWritabilityChanged, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method userEventTriggered, assume we can not skip execution
15:10:28.272 [nioEventLoopGroup-2-3] DEBUG io.netty.channel.ChannelHandlerMask - Class class io.micronaut.http.client.DefaultHttpClient$10 missing method exceptionCaught, assume we can not skip execution
those are debug level errors and are a Netty optimization that is not required for Netty to operate normally so are unrelated. Since it only fails in the lambda environment the issue is almost certainly to do with how security services are setup for the amazon linux image.
HI all, I ran some tests with the example code. Based on my tests, it looks like is going wrong with Netty and GraalVM. I'm not sure whether it's the native image tool or substrate VM itself. I have not yet tested with a GraalVM custom runtime.
List of tests and outcome below. Few notes:
provided runtime still includes the same stock JVM, Python, etc that we use in the default runtimes - I tested both the natively compiled executable from GraalVM and the fat jar with the stock JVM in the provided runtime| Test / Runtime | Stock Java 8 | Provided (GraalVM native) | Provided (Java) |
| -- | -- | -- | -- |
| Using an HttpsUrlConnection instead of Micronaut/Netty | :heavy_check_mark: | :heavy_check_mark: | :heavy_check_mark: |
| Using a low-level http client (RxHttpClient) | :heavy_check_mark: | :heavy_multiplication_x: | :heavy_check_mark: |
| Code as is | :heavy_check_mark: | :heavy_multiplication_x: | :heavy_check_mark: |
... I'll keep digging, just wanted to give an update in case you have seen this type of issue before
@sapessi Thanks for the update. Is there anything we can do to help you with this?
I think I figured out what the issue is. The Netty class io.netty.util.concurrent.ScheduledFutureTask contains a memoized static value from System.nanoTime() that all task timers are normalized to (see ScheduledFutureTask.java#L28).
Because Netty is defaulting to initialize-at-build-time, this value is computed when the native image is created, but System.nanoTime() can return an arbitrary value not one that is consistent across environments. If the value memoized in native-image is higher than the one returned by System.nanoTime() at runtime then the computed deltas go negative and get clamped to 0 causing the immediate timeout.
On a local environment the values are consistent, which explains why local testing works fine, whereas the opposite is true for Lambda where the runtime is fresh on every function update, so Lambda would be more susceptible to the problem even though there doesn't appear to be anything Lambda specific to it.
There is a straightforward fix to over-ride the initialization phase for this class (and two dependent classes) in the native-image command.
--initialize-at-run-time=io.netty.util.concurrent.GlobalEventExecutor,io.netty.util.concurrent.ImmediateEventExecutor,io.netty.util.concurrent.ScheduledFutureTask
if you can update your test to verify?
I have updated example with options --initialize-at-run-time=io.netty.util.concurrent.GlobalEventExecutor,io.netty.util.concurrent.ImmediateEventExecutor,io.netty.util.concurrent.ScheduledFutureTask
However it seems to have no effect, the same timeout exception is raised.
I also think that if these options would be the reason, then these timeouts would reproducable for http protocol as well, but what I see is that there are no problems with http urls, only for https urls timeout exception is raised.
I tested it on graal 2.1.
Exception trace is the same as in description.
@mkairys-tru That is unfortunate, is it possible that there are multiple issues at play here? I altered the native-image command at Dockerfile#L31
to
RUN /usr/lib/graalvm/bin/native-image --no-server -H:EnableURLProtocols=http,https --enable-all-security-services -H:+JNI -cp build/libs/aws-api-gateway-graal-*-all.jar --initialize-at-run-time=io.netty.util.concurrent.GlobalEventExecutor,io.netty.util.concurrent.ImmediateEventExecutor,io.netty.util.concurrent.ScheduledFutureTask
and instead of
io.micronaut.http.client.exceptions.HttpClientException: Connect Error: connection timed out: www.boredapi.com/34.237.203.145:443
i now get
{
"statusCode": 200,
"multiValueHeaders": {},
"body": "{\"activity\":Learn the Chinese erhu}",
"isBase64Encoded": false
}
as expected (I did have to make some additional changes to deserialize the activity correctly) - does that match what you tried?
Hopefully @ilopmar will be able to verify which behavior he sees with this change also, and we can solve the second issue.
@petermd Thanks for digging into this, we will take a look at verifying what you are seeing on our side
Sorry for the delay testing this. I can confirm that it works! Kudos @petermd :tada:
I've updated my test application (https://github.com/ilopmar/chuck-norris-facts-mn-graal-function) to include the configuration you mentioned and I've also upgraded it to GraalVM 19.3.1 and Micronaut 1.2.10 and everything works as expected when deployed to AWS Lambda :-)
It is failing with Micronaut 1.3.0.M2 but we've already a fix for it (https://github.com/micronaut-projects/micronaut-core/pull/2680) so it will be available in next 1.3 release.
Regarding the configuration you pass to native-image:
RUN /usr/lib/graalvm/bin/native-image --no-server -H:EnableURLProtocols=http,https --enable-all-security-services -H:+JNI -cp build/libs/aws-api-gateway-graal-*-all.jar --initialize-at-run-time=io.netty.util.concurrent.GlobalEventExecutor,io.netty.util.concurrent.ImmediateEventExecutor,io.netty.util.concurrent.ScheduledFutureTask
You don't need to add -H:EnableURLProtocols=http,httpsbecause it's already included in Micronaut (https://github.com/micronaut-projects/micronaut-core/blob/9ac3e4012583ac5a586b4e40816e54509f137244/inject/src/main/resources/META-INF/native-image/io.micronaut/inject/native-image.properties#L2)
The option --enable-all-security-services is already enabled when using https according to https://github.com/oracle/graal/blob/master/substratevm/JCA-SECURITY-SERVICES.md#jca-security-services-on-substrate-vm
Finally I'm not really sure about -H:+JNI but in my example it works without it. If you think we need it by default, please point me to some docs and we'll include it.
I've also submitted a PR to Netty to include that options: https://github.com/netty/netty/pull/9963
Glad that worked @ilopmar, and thanks for the info on the other native-image options, these were the original ones in the demo app and I had not audited them.
FYI I had already opened an issue with Netty (https://github.com/netty/netty/issues/9928) with a similar proposed change, but based on the comment on your PR there is at least one more usage of System.nanoTime that needs to be checked. I can take a look at this if you'd like?
@petermd I didn't see your issue and PR, sorry about that. The Netty team already merged my PR.
The fix on Micronaut is included in 1.3.0.RC1 and once Netty 4.1.46 is released I'll upgrade Micronaut to use it and remove my fix.
Thanks for your help! :100: