Unexpected EOF read on the socket

最近负责的SpringBoot项目日志里面老是出现“Unexpected EOF read on the socket”的错误，但是测试时，测来测去又没发现什么问题，但是看到日志里面有错误日志又不知道原因，这个怎么能忍，所以花点时间好好看看。

首先得出我的结论：在客户端上传请求体的期间，客户端关闭了网络连接，导致服务器端的输入流异常中断，最终导致Jackson反序列化出现异常。下面是具体的分析过程。 

首先我们看看错误日志：

11:00:13.792 [http-nio-9090-exec-1] ERROR com.app.component.ControllerExceptionHandler - JSON parse error: Unexpected EOF read on the socket; nested exception is com.fasterxml.jackson.databind.JsonMappingException: Unexpected EOF read on the socket (through reference chain: com.app.entity.AppServiceEntity["installList"]->java.util.HashSet[2])
 org.springframework.http.converter.HttpMessageNotReadableException: JSON parse error: Unexpected EOF read on the socket; nested exception is com.fasterxml.jackson.databind.JsonMappingException: Unexpected EOF read on the socket (through reference chain: com.app.entity.AppServiceEntity["installList"]->java.util.HashSet[2])
	at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.readJavaType(AbstractJackson2HttpMessageConverter.java:243) ~[spring-web-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.read(AbstractJackson2HttpMessageConverter.java:225) ~[spring-web-5.0.8.RELEASE.jar:5.0.8.RELEASE]

	

错误日志的调用栈其实很长，这里只截取了一小部分。从日志里面我们可以看出，错误发生的阶段应该是在服务器把请求体里面的JSON字符串反序列化成JavaBean的过程中，错误产生的原因是这个Unexpected EOF read on the socket，既然有socket肯定就跟网络有关；这里的EOF又是什么呢，EOF就是End Of File的缩写，简单理解就是文件结束标志，Unexpected EOF read on the socket直译就是在socket中出现了不该出现的EOF，意思就是在不该结束的地方就结束了，字面意思是这样，但是实际上又是什么原因导致的呢。

先百度了一下，很多帖子都说是请求超时导致的，延长服务器的连接超时时间就可以了，但是我感觉这个不科学，因为超时异常一般都是报什么SocketTimeoutException，而不是这里的Unexpected EOF，我也延长了服务器的连接超时时间，结果无济于事，说明这个说法是错误的，那导致这个问题的原因是什么呢？我初步的猜想是客户端在传输请求体的过程中，因为网络超时或者关闭，导致服务器接受到的JSON不全，进而导致JSON反序列化异常。接下来为了重现这个异常，需要写一个简单的发送HTTP请求的代码，代码如下：

public class Main {

    public static void main(String[] args) throws Exception {
        try (Socket client = new Socket()) {
            InetSocketAddress inetSocketAddress = new InetSocketAddress("localhost", 9090);
            client.connect(inetSocketAddress, 1000);

            PrintWriter writer = new PrintWriter(client.getOutputStream());

            String body = "{\"appId\":\"com.promqueen\",\"channel\":\"VIVO\"," +
                    "\"language\":\"CN\",\"deviceType\":\"ANDR\"," +
                    "\"udid\":\"21312dfhdfh44sdasd\",\"landOrPort\":\"PORT\"," +
                    "\"installList\":[\"21312dfhdfh44sdasdd\",\"21312dfhdsd\"]}";
            int bodyLength = body.getBytes(StandardCharsets.UTF_8).length;

            String header = "POST /promote_app/accom/ad_info/v1 HTTP/1.1\n" +
                    "Host: localhost:9090\n" +
                    "Content-Type: application/json;charset=UTF-8\n" +
                    "Content-Length: " + bodyLength + "\n";
            //请求头
            writer.print(header);
            //空行
            writer.println();
            //请求体
            writer.print(body);
            writer.flush();

            BufferedReader reader = new BufferedReader(new InputStreamReader(client.getInputStream()));
            String line;
            do {
                line = reader.readLine();
                System.out.println(line);
            } while (!line.equals(""));
        }
    }
}

这个代码就是向服务器发送一个POST请求，并提交JSON字符串，正常情况下会打印出响应的响应头，如下：

HTTP/1.1 200 
Content-Type: application/json;charset=UTF-8
Transfer-Encoding: chunked
Vary: Accept-Encoding
Date: Tue, 11 Aug 2020 06:38:23 GMT

响应的响应码是200，说明这个代码是正常的。我们怎么让它变得不正常呢，我最容易想到的情况就是在发送了一部分的JSON后，网络突然就阻塞或者直接断了，导致网络连接超时了，虽然我上面说了这个异常很可能不是超时导致的，我们好歹先试一试。我们把上面的发送JSON的代码改成这样：

            //先发送一部分JSON
            writer.print("{\"appId\":\"com.promqueen\",\"channel\":\"VIVO\"," +
                    "\"language\":\"CN\",\"deviceType\":\"ANDR\"," +
                    "\"udid\":\"21312dfhdfh44sdasd\",\"landOrPort\":\"PORT\"," +
                    "\"installList\":[\"21312dfhdfh44sdasdd\",\"21312dfhdsd\"");
            writer.flush();

            //模拟网络超时,在spring boot配置文件中设置超时时间为10s(server.connectionTimeout = 10000)
            Thread.sleep(15000);

            writer.print("]}");
            writer.flush();

果然服务器报错了：

15:40:51.727 [http-nio-9090-exec-1] ERROR com.app.component.ControllerExceptionHandler - JSON parse error: (was java.net.SocketTimeoutException); nested exception is com.fasterxml.jackson.databind.JsonMappingException: (was java.net.SocketTimeoutException) (through reference chain: com.app.entity.AppServiceEntity["installList"]->java.util.HashSet[1])
 org.springframework.http.converter.HttpMessageNotReadableException: JSON parse error: (was java.net.SocketTimeoutException); nested exception is com.fasterxml.jackson.databind.JsonMappingException: (was java.net.SocketTimeoutException) (through reference chain: com.app.entity.AppServiceEntity["installList"]->java.util.HashSet[1])
	

但是报的是SocketTimeoutException，不是Unexpected EOF，说明Unexpected EOF不是由于超时导致的，那么server.connectionTimeout这个参数的具体意义是什么呢？Tomcat的官网描述如下：

The number of milliseconds this Connector will wait, after accepting a connection, for the request URI line to be presented. Use a value of -1 to indicate no (i.e. infinite) timeout. The default value is 60000 (i.e. 60 seconds) but note that the standard server.xml that ships with Tomcat sets this to 20000 (i.e. 20 seconds). Unless disableUploadTimeout is set to false, this timeout will also be used when reading the request body (if any).

这个参数的意义是防止一个连接建立后被闲置过长时间，如上面的所说当Connector接受一个连接后，在收到request URI line前的最大等待时间，这里的request URI line应该就是http里面的request line，http协议中最先发送的数据，然后它最后又说这个参数还适用于读取请求体，比如我们上面的代码刚好印证了这一点，当我们在发送部分请求体数据后，停止发送数据，那么服务器在等待connectionTimeout指定的时间后，就会关闭连接，并抛出异常。这个过程通过Wireshark抓包数据如下：

NO.199客户端向服务器发送一个POST报文后，服务器返回ACK响应报文。后面客户端程序就sleep了15s，服务器在等待了大约10s（connectionTimeout）后，NO.269服务器就向客户端返回了http响应，而且响应码是400，随后在NO.275服务器向客户端发送FIN报文关闭了连接，这样就跟上面的分析是一致的。

我们再分析一下这个问题。在错误日志的调用栈里面，抛出异常的根源在这里：

 /**
     * Attempts to read some data into the input buffer.
     *
     * @return <code>true</code> if more data was added to the input buffer
     *         otherwise <code>false</code>
     */
    private boolean fill(boolean block) throws IOException {

        if (parsingHeader) {
            if (byteBuffer.limit() >= headerBufferSize) {
                if (parsingRequestLine) {
                    // Avoid unknown protocol triggering an additional error
                    request.protocol().setString(Constants.HTTP_11);
                }
                throw new IllegalArgumentException(sm.getString("iib.requestheadertoolarge.error"));
            }
        } else {
            byteBuffer.limit(end).position(end);
        }

        byteBuffer.mark();
        if (byteBuffer.position() < byteBuffer.limit()) {
            byteBuffer.position(byteBuffer.limit());
        }
        byteBuffer.limit(byteBuffer.capacity());
        int nRead = wrapper.read(block, byteBuffer);
        byteBuffer.limit(byteBuffer.position()).reset();
        if (nRead > 0) {
            return true;
        } else if (nRead == -1) {
            throw new EOFException(sm.getString("iib.eof.error"));
        } else {
            return false;
        }
    }

这个方法的全称是org.apache.coyote.http11.Http11InputBuffer.fill，如果nRead == -1 就会抛出EOFException。结合以前学过的IO流的知识，当从输入流读取数据时，返回的读取字节数如果是-1的话，对于文件IO就表示文件读完了,也就是到了"end of file"；如果是一个网络IO就表示输入流被关闭了。再想想HTTP的知识，对于使用长连接的情况下，服务器通过网络输入流读取数据时，是通过请求头Content-Length来判断请求体是否被读取完的，意思就是服务器先会去解析请求头，通过Content-Length就会知道请求体数据量的大小，然后再从输入流当中读取相应字节数的数据作为这个请求的请求体。通过上面的代码我们可以分析得出在正常情况下这个nRead是不应该为-1的，就是还有数据可以读出来，也就是还没有达到Content-Length所指定的数据量，然后输入流就关闭了。所有可以猜测出原因可能是在客户端发送JSON的过程中，在数据还没传完的情况下，连接被关闭了。我们把代码改成这样再验证一下：

            //先发送一部分JSON
            writer.print("{\"appId\":\"com.promqueen\",\"channel\":\"VIVO\"," +
                    "\"language\":\"CN\",\"deviceType\":\"ANDR\"," +
                    "\"udid\":\"21312dfhdfh44sdasd\",\"landOrPort\":\"PORT\"," +
                    "\"installList\":[\"21312dfhdfh44sdasdd\",\"21312dfhdsd\"");
            writer.flush();

            //模拟网络超时,在spring boot配置文件中设置超时时间为10s(server.connectionTimeout = 10000)
            //Thread.sleep(15000);

            //关闭输出流
            writer.close();

            //输出流关闭后再发送数据其实是没有意义的，这个代码可以注释掉
            writer.print("]}");
            writer.flush();

果然服务端抛出了Unexpected EOF read on the socket的异常信息，说明我们找到问题的原因了，就是客户端把连接给关闭了，然后服务器还没有读取到Content-Length所指定的数据量，输入流就关闭了，所以叫Unexpected EOF，就是在不该结束的时候结束了。我们还可以把代码稍微改改再来验证一下这个问题，我们把Content-Length改成先发送的部分JSON字符串的大小，看看服务器会报什么错。

//后面发送的"]}"占用了两个字节
int bodyLength = body.getBytes(StandardCharsets.UTF_8).length - 2;

·····

//不关闭输出流
//writer.close();

16:51:46.866 [http-nio-9090-exec-7] ERROR com.app.component.ControllerExceptionHandler - JSON parse error: Unexpected end-of-input: expected close marker for Array (start marker at [Source: (PushbackInputStream); line: 1, column: 141])
 at [Source: (PushbackInputStream); line: 1, column: 353]; nested exception is com.fasterxml.jackson.databind.JsonMappingException: Unexpected end-of-input: expected close marker for Array (start marker at [Source: (PushbackInputStream); line: 1, column: 141])

 这时服务器抛出的异常没有再与socket相关的异常信息了，说明我们通过修改Content-Length骗过了服务器，让它觉得接受完了请求体，但是因为接受到的JSON是不完整的，所有反序列化时会显示JSON格式不正确。

最后我们可以看出这个问题其实客户端的问题，这个接口是给app使用的，所以我觉得应该是app退出前台后，网络被关闭导致的。