The Spring Boot application starts slowly for the first time

Abstract: In a recent project, we encountered a strange phenomenon that after the spring Boot application was started, there would always be a large number of Ajax requests pedding for the first time to visit the page, and then the page would be refreshed, with a large number of ‘IOException’ errors: “`java org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe at or

In a recent project, I encountered a strange phenomenon that after the Spring Boot application was started, there would always be a large number of Ajax requests pedding when accessing the page for the first time, and then the page would be refreshed with a large number of IOException errors:

org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:356)
        at org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:815)
        at org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:720)
        at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:391)
        at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:369)
        at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:96)
        at com.fasterxml.jackson.core.json.UTF8JsonGenerator._flushBuffer(UTF8JsonGenerator.java:2039)
        at com.fasterxml.jackson.core.json.UTF8JsonGenerator._writeBytes(UTF8JsonGenerator.java:1127)
        at com.fasterxml.jackson.core.json.UTF8JsonGenerator.writeFieldName(UTF8JsonGenerator.java:253)
Copy the code

This problem exists on the server (CentOS 7) and cannot be repeated on the developer machine (Windows, Mac), which is somewhat spooky. The first thing that comes to mind is to check opinions in the log. The log level is set to DEBUG, and the entire process is started. No obvious exception is found, but several similar lines are found before IOException:

[12-05 13:54:32. 912 | WARN | 3 | 1 - exec - O.A.C atalina. Util. SessionIdGeneratorBase. Log: 179] Creation of SecureRandom instance For the session ID generation using [SHA1PRNG] took [67400] milliseconds. [12-05 13:54:32. 915 | WARN|1-exec-2|o.a.catalina.util.SessionIdGeneratorBase.log:179] Creation of SecureRandom instance for session ID Generation using [SHA1PRNG] took [67401] milliseconds. [12-05 13:54:32. 912 | WARN|-exec-12|o.a.catalina.util.SessionIdGeneratorBase.log:179] Creation of SecureRandom instance for session ID Generation using [SHA1PRNG] took [7738] milliseconds. [12-05 13:54:32. 917 | WARN|1-exec-9|o.a.catalina.util.SessionIdGeneratorBase.log:179] Creation of SecureRandom instance for session ID Generation using [SHA1PRNG] took [7755] milliseconds. [12-05 13:54:32. 917 | WARN|1-exec-7|o.a.catalina.util.SessionIdGeneratorBase.log:179] Creation of SecureRandom instance for session ID Generation using [SHA1PRNG] took [7,755] milliseconds.Copy the code

This is obviously taking too long to generate the Session ID. To prove this, I execute the jstack ${pid} command during the page Ajax hang to display the memory stack during the hang. The stack looks like this (condensed) :

"http-nio-7001-exec-4" #47 daemon prio=5 os_prio=0 tid=0x00007f851609b000 nid=0x34c7 in Object.wait() [0x00007f84befed000]
   java.lang.Thread.State: RUNNABLE
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:221)
    - locked <0x00000000f517be18> (a sun.security.provider.SecureRandom)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:468)
    at java.security.SecureRandom.next(SecureRandom.java:491)
    at java.util.Random.nextInt(Random.java:329)
    at org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom(SessionIdGeneratorBase.java:269)
    at org.apache.catalina.util.SessionIdGeneratorBase.getRandomBytes(SessionIdGeneratorBase.java:203)
    at org.apache.catalina.util.StandardSessionIdGenerator.generateSessionId(StandardSessionIdGenerator.java:34)
    at org.apache.catalina.util.SessionIdGeneratorBase.generateSessionId(SessionIdGeneratorBase.java:195)
    at org.apache.catalina.session.ManagerBase.generateSessionId(ManagerBase.java:831)
    at org.apache.catalina.session.ManagerBase.createSession(ManagerBase.java:663)
    at org.apache.catalina.connector.Request.doGetSession(Request.java:3039)
    at org.apache.catalina.connector.Request.getSession(Request.java:2429)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:896)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:908)
    ......

"http-nio-7001-exec-3" #46 daemon prio=5 os_prio=0 tid=0x00007f8515910800 nid=0x34c6 in Object.wait() [0x00007f84bf0ee000]
   java.lang.Thread.State: RUNNABLE
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:221)
    - locked <0x00000000f5096b80> (a sun.security.provider.SecureRandom)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:468)
    at java.security.SecureRandom.next(SecureRandom.java:491)
    at java.util.Random.nextInt(Random.java:329)
    at org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom(SessionIdGeneratorBase.java:269)
    at org.apache.catalina.util.SessionIdGeneratorBase.getRandomBytes(SessionIdGeneratorBase.java:203)
    at org.apache.catalina.util.StandardSessionIdGenerator.generateSessionId(StandardSessionIdGenerator.java:34)
    at org.apache.catalina.util.SessionIdGeneratorBase.generateSessionId(SessionIdGeneratorBase.java:195)
    at org.apache.catalina.session.ManagerBase.generateSessionId(ManagerBase.java:831)
    at org.apache.catalina.session.ManagerBase.createSession(ManagerBase.java:663)
    at org.apache.catalina.connector.Request.doGetSession(Request.java:3039)
    at org.apache.catalina.connector.Request.getSession(Request.java:2429)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:896)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:908)
    ......

"http-nio-7001-exec-1" #44 daemon prio=5 os_prio=0 tid=0x00007f8514970800 nid=0x34c4 runnable [0x00007f84bf2ef000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:255)
    at sun.security.provider.SeedGenerator$URLSeedGenerator.getSeedBytes(SeedGenerator.java:539)
    at sun.security.provider.SeedGenerator.generateSeed(SeedGenerator.java:144)
    at sun.security.provider.SecureRandom$SeederHolder.<clinit>(SecureRandom.java:203)
    at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:221)
    - locked <0x00000000f7173220> (a sun.security.provider.SecureRandom)
    at java.security.SecureRandom.nextBytes(SecureRandom.java:468)
    at java.security.SecureRandom.next(SecureRandom.java:491)
    at java.util.Random.nextInt(Random.java:329)
    at org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom(SessionIdGeneratorBase.java:269)
    at org.apache.catalina.util.SessionIdGeneratorBase.getRandomBytes(SessionIdGeneratorBase.java:203)
    at org.apache.catalina.util.StandardSessionIdGenerator.generateSessionId(StandardSessionIdGenerator.java:34)
    at org.apache.catalina.util.SessionIdGeneratorBase.generateSessionId(SessionIdGeneratorBase.java:195)
    at org.apache.catalina.session.ManagerBase.generateSessionId(ManagerBase.java:831)
    at org.apache.catalina.session.ManagerBase.createSession(ManagerBase.java:663)
    at org.apache.catalina.connector.Request.doGetSession(Request.java:3039)
    at org.apache.catalina.connector.Request.getSession(Request.java:2429)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:896)
    at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:908)
    ......Copy the code

A large number of threads hang in the sun, the security provider. SecureRandom. EngineNextBytes (phase SecureRandom. Java: 221). [bug fixes] [bug fixes] [bug Fixes] [bug Fixes] [BUG Fixes] [BUG Fixes] [BUG Fixes] [BUG Fixes] [BUG Fixes] [BUG Fixes] [BUG Fixes] [bug Fixes] [bug Fixes] [bug Fixes] [bug Fixes] But obviously not completely fixed. JVM Delays by Random Number Generation, How do I make Tomcat startup faster? , just record the reason why the random number generation is slow and the solution.

Java random number generation depends on the Entropy Source. The default blocking Source of /dev/random Entropy can cause blocking, and a non-blocking Source of /dev/urandom Entropy can cause blocking.

Avoiding JVM Delays Caused by Random Number Generation
-Djava.security.egd=file:/dev/./urandom
-jar
-jar

The Spring Boot application starts slowly for the first time

Related Posts

Prometheus custom burial position ii of the SpringBoot series

Walk you through the raspberry PI transplant of LiteOS

When cloud native meets Hybrid Cloud: How to achieve the balance between “change” and “stability”