最近一个项目中,遇到了一个奇怪的现象,spring boot应用启动后,第一次访问页面总是会有大量的ajax请求pedding,然后刷新页面,大量的IOException
错误:
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)
这个问题存在于服务器(CentOS 7)上,在开发者机器(Windows、Mac)上无法复现,这就比较诡异了。首先想到的是日志查看法。日志级别设为debug,查看启动整个流程,没有发现明显异常,只是看到在IOException
之前发现有连续的几行类似的日志:
[12-05 13:54:32.912| WARN|1-exec-3|o.a.catalina.util.SessionIdGeneratorBase.log:179] Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [67,400] 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 [67,401] 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 [7,738] 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 [7,755] 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.
这明显是在生成Session ID上消耗了太长的时间。为了证明这一点,我在页面ajax hang住期间,执行jstack ${pid}
命令,显示hang住期间的内存堆栈。堆栈显示如下(有精简):