Micronaut-core: Micronaut Server Error - No request state present (Connection Reset by Peer)

[brianwyka]

Task List

• [ ] Steps to reproduce provided
• [x] Stacktrace (if present) provided
• [ ] Example that reproduces the problem uploaded to Github
• [x] Full description of the issue provided (see below)

Steps to Reproduce

1. start up the server and witness error

19:23:12.811 [nioEventLoopGroup-1-2] ERROR i.m.h.s.netty.RoutingInBoundHandler - Micronaut Server Error - No request state present. Cause: Connection reset by peer
--
  | java.io.IOException: Connection reset by peer
  | at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
  | at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
  | at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
  | at sun.nio.ch.IOUtil.read(IOUtil.java:192)
  | at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
  | at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:253)
  | at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1133)
  | at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:350)
  | at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148)
  | at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
  | at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
  | at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
  | 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.lang.Thread.run(Thread.java:748)

Expected Behaviour

This exception should not be thrown.

Actual Behaviour

This exception is thrown. There is not enough information in the stacktrace to determine source. Perhaps a health check or info source?

Environment Information

• Operating System: Linux
• Micronaut Version: 1.3.4
• JDK Version: 1.8.222
• Micronaut Kafka Version: 2.0.0

Example Application

pom.xml dependencies:

 <dependencies>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-discovery-client</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-security</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micronaut.configuration</groupId>
            <artifactId>micronaut-security-ldap</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-management</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micronaut.configuration</groupId>
            <artifactId>micronaut-micrometer-registry-statsd</artifactId>
        </dependency>
        <dependency>
            <groupId>com.github.jknack</groupId>
            <artifactId>handlebars</artifactId>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut.configuration</groupId>
            <artifactId>micronaut-openapi</artifactId>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-views</artifactId>
        </dependency>
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>com.google.guava</groupId>
            <artifactId>guava</artifactId>
            <version>27.0.1-jre</version>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>commons-io</groupId>
            <artifactId>commons-io</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>commons-cli</groupId>
            <artifactId>commons-cli</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>org.apache.commons</groupId>
            <artifactId>commons-lang3</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.dataformat</groupId>
            <artifactId>jackson-dataformat-xml</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.dataformat</groupId>
            <artifactId>jackson-dataformat-yaml</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.vavr</groupId>
            <artifactId>vavr</artifactId>
            <version>0.10.0</version>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.jsonwebtoken</groupId>
            <artifactId>jjwt</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-inject</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-validation</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-runtime</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-http-client</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-http-server-netty</artifactId>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-inject-java</artifactId>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-core</artifactId>
            <scope>runtime</scope>
        </dependency>
        <dependency>
            <groupId>cglib</groupId>
            <artifactId>cglib-nodep</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut</groupId>
            <artifactId>micronaut-inject-groovy</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.micronaut.test</groupId>
            <artifactId>micronaut-test-spock</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.objenesis</groupId>
            <artifactId>objenesis</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.projectreactor</groupId>
            <artifactId>reactor-core</artifactId>
            <scope>test</scope>
        </dependency>
    </dependencies>

All the dependencies of the classpath:

   io.micronaut:micronaut-discovery-client:jar:1.3.4:compile
   org.slf4j:slf4j-api:jar:1.7.29:compile
   io.micronaut:micronaut-security:jar:1.4.0:compile
   io.micronaut:micronaut-http:jar:1.3.4:compile
   io.micronaut:micronaut-http-server:jar:1.3.4:compile
   io.micronaut:micronaut-security-annotations:jar:1.4.0:compile
   com.optum.cirrus.micronaut:micronaut-security-jwt:jar:5.0.0:compile
   io.micronaut.configuration:micronaut-security-ldap:jar:1.4.0:compile
   io.micronaut:micronaut-management:jar:1.3.4:compile
   io.micronaut:micronaut-router:jar:1.3.4:compile
   io.micronaut.configuration:micronaut-micrometer-registry-statsd:jar:1.3.0:compile
   io.micrometer:micrometer-core:jar:1.3.6:compile
   org.hdrhistogram:HdrHistogram:jar:2.1.11:compile
   org.latencyutils:LatencyUtils:jar:2.0.3:compile
   io.micronaut.configuration:micronaut-micrometer-core:jar:1.3.0:compile
   javax.validation:validation-api:jar:2.0.1.Final:compile
   io.micrometer:micrometer-registry-statsd:jar:1.3.6:compile
   com.github.jknack:handlebars:jar:4.1.2:runtime
   io.micronaut.configuration:micronaut-openapi:jar:1.4.1:compile
   io.swagger.core.v3:swagger-core:jar:2.1.1:compile
   javax.xml.bind:jaxb-api:jar:2.3.1:provided
   javax.activation:javax.activation-api:jar:1.2.0:provided
   io.swagger.core.v3:swagger-models:jar:2.1.1:compile
   io.swagger.core.v3:swagger-annotations:jar:2.1.1:compile
   io.micronaut:micronaut-views:jar:1.3.1:compile
   io.micronaut:micronaut-views-core:jar:1.3.1:compile
   io.micronaut:micronaut-views-freemarker:jar:1.3.1:compile
   io.micronaut:micronaut-views-handlebars:jar:1.3.1:compile
   io.micronaut:micronaut-views-soy:jar:1.3.1:compile
   io.micronaut:micronaut-views-thymeleaf:jar:1.3.1:compile
   io.micronaut:micronaut-views-velocity:jar:1.3.1:compile
   org.projectlombok:lombok:jar:1.18.10:provided
   com.google.guava:guava:jar:27.0.1-jre:compile
   com.google.guava:failureaccess:jar:1.0.1:compile
   com.google.guava:listenablefuture:jar:9999.0-empty-to-avoid-conflict-with-guava:compile
   com.google.code.findbugs:jsr305:jar:3.0.2:compile
   org.checkerframework:checker-qual:jar:2.5.2:compile
   com.google.errorprone:error_prone_annotations:jar:2.3.3:compile
   com.google.j2objc:j2objc-annotations:jar:1.1:compile
   org.codehaus.mojo:animal-sniffer-annotations:jar:1.17:compile
   commons-io:commons-io:jar:2.6:compile
   commons-cli:commons-cli:jar:1.4:compile
   org.apache.commons:commons-lang3:jar:3.9:compile
   com.fasterxml.jackson.dataformat:jackson-dataformat-xml:jar:2.10.3:compile
   com.fasterxml.jackson.core:jackson-core:jar:2.10.3:compile
   com.fasterxml.jackson.core:jackson-annotations:jar:2.10.3:compile
   com.fasterxml.jackson.core:jackson-databind:jar:2.10.3:compile
   com.fasterxml.jackson.module:jackson-module-jaxb-annotations:jar:2.10.3:compile
   jakarta.xml.bind:jakarta.xml.bind-api:jar:2.3.2:compile
   jakarta.activation:jakarta.activation-api:jar:1.2.1:compile
   org.codehaus.woodstox:stax2-api:jar:4.2:compile
   com.fasterxml.woodstox:woodstox-core:jar:6.1.1:compile
   com.fasterxml.jackson.dataformat:jackson-dataformat-yaml:jar:2.10.3:compile
   org.yaml:snakeyaml:jar:1.24:compile
   io.vavr:vavr:jar:0.10.0:compile
   io.vavr:vavr-match:jar:0.10.0:compile
   io.jsonwebtoken:jjwt:jar:0.9.1:compile
   io.micronaut:micronaut-inject:jar:1.3.4:compile
   javax.annotation:javax.annotation-api:jar:1.3.2:compile
   javax.inject:javax.inject:jar:1:compile
   io.micronaut:micronaut-core:jar:1.3.4:compile
   io.micronaut:micronaut-validation:jar:1.3.4:compile
   io.micronaut:micronaut-runtime:jar:1.3.4:compile
   io.micronaut:micronaut-aop:jar:1.3.4:compile
   io.reactivex.rxjava2:rxjava:jar:2.2.12:compile
   com.fasterxml.jackson.datatype:jackson-datatype-jdk8:jar:2.10.3:compile
   com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.10.3:compile
   io.micronaut:micronaut-http-client:jar:1.3.4:compile
   io.micronaut:micronaut-websocket:jar:1.3.4:compile
   io.micronaut:micronaut-http-netty:jar:1.3.4:compile
   io.micronaut:micronaut-buffer-netty:jar:1.3.4:compile
   io.netty:netty-handler:jar:4.1.48.Final:compile
   io.netty:netty-resolver:jar:4.1.48.Final:compile
   io.netty:netty-handler-proxy:jar:4.1.48.Final:compile
   io.netty:netty-common:jar:4.1.48.Final:compile
   io.netty:netty-buffer:jar:4.1.48.Final:compile
   io.netty:netty-transport:jar:4.1.48.Final:compile
   io.netty:netty-codec:jar:4.1.48.Final:compile
   io.netty:netty-codec-socks:jar:4.1.48.Final:compile
   io.micronaut:micronaut-http-server-netty:jar:1.3.4:compile
   io.netty:netty-codec-http:jar:4.1.48.Final:compile
   io.micronaut:micronaut-inject-java:jar:1.3.4:provided
   ch.qos.logback:logback-classic:jar:1.2.3:runtime
   ch.qos.logback:logback-core:jar:1.2.3:runtime
   cglib:cglib-nodep:jar:3.2.12:test
   io.micronaut:micronaut-inject-groovy:jar:1.3.4:test
   org.codehaus.groovy:groovy:jar:2.5.8:test
   io.micronaut.test:micronaut-test-spock:jar:1.1.5:test
   io.micronaut.test:micronaut-test-core:jar:1.1.5:test
   org.spockframework:spock-core:jar:1.2-groovy-2.5:test
   org.codehaus.groovy:groovy-json:jar:2.5.8:test
   org.codehaus.groovy:groovy-nio:jar:2.5.2:test
   org.codehaus.groovy:groovy-macro:jar:2.5.2:test
   org.codehaus.groovy:groovy-templates:jar:2.5.4:test
   org.codehaus.groovy:groovy-test:jar:2.5.8:test
   org.codehaus.groovy:groovy-sql:jar:2.5.2:test
   org.codehaus.groovy:groovy-xml:jar:2.5.4:test
   junit:junit:jar:4.12:test
   org.hamcrest:hamcrest-core:jar:1.3:test
   org.objenesis:objenesis:jar:2.6:test
   io.projectreactor:reactor-core:jar:3.3.0.RELEASE:test
   org.reactivestreams:reactive-streams:jar:1.0.3:compile

application.yml relevant configurations:

---
# Application and Server Configurations
micronaut:
  application:
    name: service

application:
  environment: ${APPLICATION_ENVIRONMENT:local}

---
# Server Configurations

micronaut:
  server:
    port: 8080
    cors:
      enabled: true
      configurations:
        web:
          maxAge: 3600 # 1 hour
  config-client:
    enabled: false

---
# Endpoints Configuration

endpoints:
  info:
    enabled: true
    sensitive: false
  routes:
    enabled: true
    sensitive: false
  health:
    enabled: true
    sensitive: false
    details-visible: ANONYMOUS

---
# Metrics Configuration

micronaut:
  metrics:
    enabled: true
    export:
      statsd:
        enabled: true
        flavor: datadog
        step: PT1M
        host: localhost
        port: 8125

---
# Security Configuration

micronaut:
  security:
    enabled: true

---

# Swagger Configurations

swagger:
  path: /swagger/api-docs
  version: 3.22.1
  layout: StandaloneLayout
  deepLinking: true
  urls:
    - name: service
      url: ${swagger.path}/service-1.0.X.yml

---
# Static Resource and View Definitions

micronaut:
  router:
    static-resources:
      swagger:
        enabled: true
        paths: classpath:META-INF/swagger
        mapping: ${swagger.path}/**
  views:
    enabled: true
    folder: /views
    handlebars:
      enabled: true

---
# Http Client Configurations

micronaut:
  http:
    client:
      connect-timeout: 10s

[graemerocher]

If you could provide an example that reproduces the issue that would help a great deal.

[brianwyka]

I'll try to do that over the weekend. Confirmed this issue in a non kafka application as well. Seems that its limited to netty. This happened when we upgraded from MN 1.3.3 to 1.3.4. Will try to get an example app uploaded or diagnose the issue.

[brianwyka]

I see that netty was upgraded from 4.1.47.Final to 4.1.48.Final in that release so I will see if the issue still persists with previous versions.

[gastonestol]

Any solutions to this issue?

[brianwyka]

Just an update on this. I'm still getting this with Micronaut 2.0.0 stack.

[gastonestol]

I left netty and used the tomcat server dependecy instead and worked like a charm!

[gastonestol]

I see that netty was upgraded from 4.1.47.Final to 4.1.48.Final in that release so I will see if the issue still persists with previous versions.

I tried this and it didn't worked out, seems to be a problem with the last release of netty

[mmanes]

In my case, this was caused by haproxy's L4 health checks, which only connect and don't actually perform an HTTP request. Turning it off got rid of the log message, and while I didn't test it, I expect real HTTP endpoint health check would get rid of it as well.

[brianwyka]

@mmanes, this makes sense, considering its happening on an interval / periodic basis. @graemerocher, @jameskleeh is there any way to suppress this type of error or handle it more gracefully?

[jameskleeh]

@brianwyka Probably, however an example app that reproduces the issue would be needed to determine this best fix

[brianwyka]

@mmanes, does a simple hello world app produce the issue with a CONNECT only health check? Is it TCP?

[mmanes]

@brianwyka I tried on two different basic micronaut applications, so it seems so. It should be easily reproducible by adding haproxy in front of the application while having check inter 10s on the backend server configuration. haproxy simply establishes a TCP connection then immediately sends an RST.

Modifying haproxy to use HTTP health checks with something like: option httpchk GET /health HTTP/1.0 prevents the errors from being logged, and is a better health check anyway.

http://cbonte.github.io/haproxy-dconv/2.3/configuration.html#check

[meredrica]

I have this problem too, with Micronaut 2.2.0
For us, this only happens if we have 2 pods running at the same time.
Our config is very similar to the OP. I have a feeling the metrics endpoint is the culprit.
I added a full trace log (had to remove minimal stuff like jdbc urls and env variables)

micronaut:
  application:
    name: auth
  metrics:
    enabled: false
    export:
      prometheus:
        enabled: true
        step: PT1M
        descriptions: true
  server:
    netty:
      worker:
        threads: 10
        childOptions:
          autoRead: false
          autoClose: true


  security:
    authentication: bearer
    token:
      jwt:
        signatures:
          secret:
            generator:
              secret: ${jwt.secret}
              jws-algorithm: ${jwt.algorithm}
  caches:
    users:
      expire-after-write: 2m
---
endpoints:
  health:
    sensitive: false
  prometheus:
    sensitive: false
---
datasources:
  default:
    url: jdbc:${user-service.postgres.uri}
    driver-class-name: org.postgresql.Driver
    dialect: POSTGRES
    maximum-pool-size: 4
---
flyway:
  datasources:
    default:
      locations: classpath:databasemigrations
      url: jdbc:${user-service.postgres.uri}
      schemas:
        - app
---
carhub:
  proxy:
    config:
      - path: /api/v./vehicles/.*
        host: export-service:8080
        methods:
          - GET
      - path: /api/v./export/.*
        host: export-service:8080
      - path: /api/v./reservation/.*
        host: reservation-broker:8080
      - path: /api/v2/salescontract/.*
        host: sc-broker:8080
      - path: .*
        host: carhub:8080

log.txt

[meredrica]

Verfied the health checks again. It's not them.
The last thing that's shared by the two pods in openshift is the DB connection. We use jdbc with hikari.
This only starts happening if we scale up to 2 pods. the moment we scale down, exceptions are gone.
Any pointers where this could come from?

[graemerocher]

Seems like client connections being dropped unexpectedly. The error should be handled more gracefully by Micronaut though and simply logged to debug level

[meredrica]

I'm not sure if this isn't a timeout issue of some sort. I see multiple exceptions in rapid succession and then silence again.

[brianwyka]

@jameskleeh, just opened https://github.com/micronaut-projects/micronaut-core/pull/4807 to change logging to DEBUG. Is this sufficient?

[meredrica]

This still happens multiple times per second for us, I don't think changing this to a debug log will actually fix anything (micronaut 2.2.3). I wonder why this occurs in the first place. We are not dropping that many connections at all. Even just running the pods idle in oc with only health and prometheus requests as traffic gives us these errors.

[graemerocher]

@meredrica if you have a way to reproduce we can try get to the bottom of it

[americ]

this code is supposed to suppress logging of these connection reset exceptions: https://github.com/micronaut-projects/micronaut-core/blob/8e79eac72cf1ce70fac62a74882db2a618d154a2/http-server-netty/src/main/java/io/micronaut/http/server/netty/RoutingInBoundHandler.java#L154

Since upgrading to Micronaut 2.x these connection resets have become more problematic. We used to hide them to keep our request logging from recording them. Now that's not sufficient because they are being counted as 500's in our prometheus metrics (in addition to the 200 for the real response). All the connection resets I've seen have come after the real response has been sent back to the client. It would be nice if connection resets that happen after the response is out the door are explicitly ignored, rather than relying on exception handling magic (and now metrics magic).

In our case the connection resets don't happen when calling the endpoints from inside the same k8s cluster. Something in our k8s network plumbing seems to be terminating connections in a way that netty doesn't like.

If these resets can't be avoided entirely, it would be nice if ExceptionHandlers could return null to indicate there is no response to send. Currently custom exception handlers are required to return a response object, or have RoutingInBoundHandler create a default 500 response.

[meredrica]

@americ that sounds almost exactly like our problem. my team is not managing the cluster so we can't change the behaviour. it also explains why this only happens when we have more than one pod.
@brianwyka I think it might be better to just reuse the logException method in #4807 instead of just dropping it to debug.

[lgathy]

I had issues previously with the built-in web metrics. Wierd things happened when the meter reporting logic threw RuntimeException-s, because they were not handled in the subscriber. Plus, I think most web filters don't work correctly in cases when there are multiple execution chains, which is the case if you let an exception fall through the controller method and handle it via an error handler method. I made this mistake myself as well with the tracing filters, see: #4314

I ended up writing a local replacement for the web metrics filters - they cannot really be extended - which solved those issues for me. @americ, @meredrica I am happy to share it with you so that you can check if it resolves the issues in your apps, I just need some time to extract it from my project.

[americ]

@lgathy I'm interested in seeing your solution. Our current workaround maps these errors to status code 100, which avoids it being counted as a success or failure in our alert system.

[jameskleeh]

@americ I've created this PR which ignores client connection related exceptions. You can try the snapshot after its merged or build it yourself and try https://github.com/micronaut-projects/micronaut-core/pull/4867

[americ]

@jameskleeh we have a global exception handler that's a workaround for this issue. It looks like your change only affects apps with no exception handler defined. If I understand our code and yours, I think we can get rid of our exception handler now. I believe we added it so we could tag these fake 500 responses so our request logging filter could discard them. We'll try out the snapshot build.

[americ]

@jameskleeh I just tried 2.3.1-SNAPSHOT and the connection reset handling works great. They aren't affecting our prometheus metrics any more and we don't need an exception handler. I was worried the exception handler removal would affect our response logging, but it doesn't.

Two big thumbs up!

[jameskleeh]

@americ Glad to hear