Nginx request line 换行导致的 400 异常分析

Posted on | Edited on | In | Comments:

原创文章，如需转载，请注明来自：https://bigzuo.github.io/

NGINX 处理转发请求时报错

最近在做一个需求时，NGINX 出现了 400 异常。具体细节如下：有两台独立的 NGINX，每一台 NGINX 都能正常的处理请求。但是当我用 lua 脚本，将一台 NGINX 接收到的请求筛选后，转发给另外一台 NGINX 处理时，收到如下 400 响应： 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
HTTP/1.1 400 Bad Request
Server: openresty/1.11.2.2
Date: Mon, 06 Aug 2018 13:36:20 GMT
Content-Type: text/html
Content-Length: 179
Connection: close
 
<html>
<head><title>400 Bad Request</title></head>
<body bgcolor="white">
<center><h1>400 Bad Request</h1></center>
<hr><center>openresty/1.11.2.2</center>
</body>
</html>

而另外一台 NGINX 的 access 日志中，只显示请求响应 400，error 日志中无其他报错。当我用 postman 或者 curl 命令直接请求这台 NGINX 时，响应一切正常。 curl 命令内容如下： 

1
2
3
4
curl --request POST \
  --url http://127.0.0.1:80/root/do/uri \
  --header 'beta: 1' \
  --data 'param1=aWBIWi7VwmZE0kQqHcyUIZ1wy4I9b99p8wNLiL0IOzYNv5Dz61Pv620shbsolqBCw%252B8S6rNzLywb%250AJ5dBwjPtc6h%252BxJoTuP4h%252Bi6kd5CFx%252BBWQgvjIFDIdbwfb0WpnkBc%252FE3aDQJJbmajLnJM3NHjaw%253D%253D%250A&param1 =4220'

在将 NGINX 的 error 日志调成 debug 级别后，重新复现问题时，发现 NGINX 在响应400 时，会有一行 info 级别的报错： 

1
2018/08/06 16:15:01 [info] 280#0: *251 client sent invalid request while reading client request line, client: 215.131.75.20, server: ng_instance, request: "POST /uri-path"

根据报错信息显示 “NGINX 在读取请求行时，发现客户端发起的是一个无效请求”，而又结合直接请求这台 NGINX 时响应正常的现象分析，第一台 NGINX 在转发请求时，发起的请求可能有问题。在第二台 NGINX 上使用 tcpdump 命令抓包分析正常请求和异常请求的内容时，发现被转发的异常请求的 request line 中有换行，除此外无其他任何区别：

  • 正常请求
1
2
3
4
5
6
7
8
9
10
11
POST /uri-path HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.3.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Host: 215.131.72.4
Accept: */*
Content-Type: application/x-www-form-urlencoded
beta: 1
X-Forwarded-Host: 127.0.0.1
X-Real-IP: 127.0.0.1
X-Forwarded-Server: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Content-Length: 212
  • 被转发的异常请求
1
2
3
4
5
6
7
8
9
10
11
12
POST /uri-path
HTTP/1.1
Host: 127.0.0.1
X-Forwarded-Host: 127.0.0.1
X-Real-IP: 127.0.0.1
X-Forwarded-Server: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Content-Length: 212
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.3.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Accept: */*
Content-Type: application/x-www-form-urlencoded
beta: 1

既然只发现这一处差异，那是不是 request line 中有换行导致 NGINX 在处理请求时出现 400 异常呢？

什么是正确的 request line ？

首先看一下 RFC 2616 定义的标准 HTTP 请求的格式：

1
2
3
4
5
6
Request       = Request-Line                    
                        *(( general-header      
                         | request-header       
                         | entity-header ) CRLF)
                        CRLF
                        [ message-body ]

第一行就是 Request-Line，Request-Line 显示了请求的方式、请求资源的位置及使用的 HTTP 协议版本。根据 RFC 2616 文档定义，Request-Line 是由三部分组成：请求方法+Request-URI+HTTP-Version，而且这三部分之间，只能用空格（Space）分开，Request-Line 的最后部分，必须是一个换行符（CRLF）。根据这个定义，异常请求的 request line 中有个换行一定是不合法的。

1
2
3
4
5
6
7
8
5.1 Request-Line

	The Request-Line begins with a method token, followed by the
	Request-URI and the protocol version, and ending with CRLF. The
	elements are separated by SP characters. No CR or LF is allowed
	except in the final CRLF sequence.
	
	    Request-Line   = Method SP Request-URI SP HTTP-Version CRLF

NGINX 读取 request line 与 400 异常

NGINX 接收到请求后，会对请求进行解析。在 NGINX 实现中，会根据 HTTP 协议规范实现一个有限状态机，NGINX 在解析请求时，会经过这个状态机。在读取 request line 时，NGINX 会记录请求方法、URI 信息及 HTTP 协议信息，以及其他有用的信息放在缓存中，以便后面流程使用。如果请求行处理正常，接着会按照状态机流程处理请求头。但是在处理请求行时，如果客户端提前关闭连接、或者请求行不符合协议规范，读取数据时发生了错误，NGINX 就会立刻终止请求解析，同时给客户端返回一个400错误。当然，如果是客户端提前关闭了连接，400 错误就无法正常到达客户端。因此，被 NGINX 转发的请求，由于 request line 多了一个换行，所以 NGINX 返回了 400 BAD REQUEST 异常。

那么，这个换行是怎么来的呢？

哪里来的换行？

在我们实现的逻辑中，我们会把需要被 NGINX 转发的接口放到一个配置文件中，当需要增加或减少接口时，直接修改配置文件即可：

1
2
3
4
5
6
7
8
9
10
/uri-path0#/new-uri-path0
/uri-path1#/new-uri-path1
/uri-path2#/new-uri-path2
/uri-path3#/new-uri-path3
/uri-path4#/new-uri-path4
/uri-path5#/new-uri-path5
/uri-path6#/new-uri-path6
/uri-path7#/new-uri-path7
/uri-path8#/new-uri-path8
/uri-path9#/new-uri-path9

配置文件中的每一行都有两部分组成：原 URI 和目的 URI，中间用“#”号隔开，且原 URI 和目的 URI 不一样。我们的需求就是如果 NGINX 接收的请求在这个配置文件中，则将请求的URI 替换成目的 URI，然后转发给另外一台 NGINX 处理。

我们用 lua 脚本一行行读取这个配置文件，然后解析成原 URI 和目的 URI，存放在共享内存中。刚开始的时候，功能一直正常，请求转发和请求处理都可以正常处理。几天之后，NGINX 在处理转发请求时，开始报 400 异常。同时，我们从日志中也观察到，客户端 NGINX 在进行 URI 替换时， 日志中输出的替换后的 URI会多一个^M符号。为什么之前日志中没有这个符号，现在突然多个这个符号呢？这个符号又是什么意思呢？

1
2018/08/06 22:11:28 [debug] 362#362: *1842 [lua] requestRewrite.lua:60: requestRewrite(): rewrite module target uri is /new-uri-path9^M

其实 Linux/Unix 系统、Mac 系统和 DOS/Windows 系统在处理文本文件时，对换行处理是不一样的。Windows 中的换行符是\r\n，Linux/Unix 下的换行符是\n， Mac 系统是\r。其中\r表示的是回车，\n是换行。因为对换行处理的不一致，导致 Windows 系统的文本文件在 Linux/Unix
打开时，每行的结尾会多一个^M符号；而 Linux/Unix 系统的文本文件在 Windows 中打开时，所有行都会变成一行。

而导致我们这次问题的原因，就是因为最开始大家在编辑这个配置文件的时候，使用的都是 Mac 电脑，即 Unix 系统。后来，其他同事使用 Windows 电脑编辑这个配置文件，并上传到服务器。lua 脚本在读取配置文件的时候，每一行后面都多个了一个\r，即换行符，因此解析得到的目的 URI，也多了一个换行符。所以，客户端 NGINX 在转发请求的时候，request line 中多了一个换行符，导致目的 NGINX 在解析的时候报错。

所以，lua 在读取配置文件时，增加对换行的兼容，问题得到解决。

处理‘^M’ 方式

当在 Linux/Unix 系统打开 Windows 的文本文件出现^M符号时，可以很简单通过下面方式解决： 

1
cat file | sed 's/^M//' > newfile

或者：

1
cat file | tr -d '\r' > newfile

参考文档

Nginx giving 400 error
nginx的请求处理阶段 (90%)
nginx中http request处理的流程
How to Remove ^M in Linux & Unix
lua文件读取注意事项
VIM 小技巧 - replace ‘^M’