nginx 報500 Internal Server Error
這個問題是其他同事反映過來的,應該說比較罕見,需要同時滿足三種條件才能發生。為了保持神祕,原因暫時不提,不過背景得交待一下。該案例的大概架構就是部署兩個nginx伺服器,nginx1作為普通的web server,nginx2作為反向代理部署在nginx1的後端。出於測試目的,取消了臨時檔案所在目錄client_body_temp的訪問許可權,此為條件一 。
關於client_body_temp目錄的作用,簡單說就是如果客戶端POST一個比較大的檔案,長度超過了nginx緩衝區的大小,需要把這個檔案的部分或者全部內容暫存到client_body_temp目錄下的臨時檔案。
引起我們注意的是nginx的一個配置指令,client_body_buffer_size,如果把它設定為比較大的數值,例如256k,那麼,無論使用firefox還是IE瀏覽器,來提交任意小於256k的圖片,都很正常。如果註釋該指令,使用預設的client_body_buffer_size設定,也就是作業系統頁面大小的兩倍,8k或者16k(此為條件二
無論使用firefox4.0還是IE8.0,提交一個比較大,200k左右的圖片,都返回500 Internal Server Error錯誤。這其實也沒有問題,200k大於當前的client_body_buffer_size(8k或者16k),提交的內容需要寫入臨時檔案,前面取消了目錄訪問許可權導致出錯。
但是,如果提交一個比較小,30k左右的圖片,firefox和IE的返回結果卻有所不同。IE仍然返回500錯誤,這很好理解,30k仍然大於當前的client_body_buffer_size(8k或者16k),出錯是正常的,不出錯才奇怪。然而,firefox就是神奇地返回了經過resize server處理後的頁面!
這太奇怪了,難道firefox傳送的資料與IE傳送的有所不同?使用tcpdump抓包發現,的確是有很大的不一樣。
IE傳送的資料包截圖如下,建立連線時三次握手清晰可見,第10行是IE向nginx1傳送http頭訊息,第24行是nginx1傳送應答,然後再發送Content-Disposition和Content-Type兩行header和body。Body與header的主幹部分是分開不同的包傳送的。
而firefox傳送的資料包截圖如下,三次握手不再贅述,第13行是firefox向nginx1傳送http頭訊息,奇怪的是除了傳送頭訊息,還附帶了部分body,見第33行,第35行才是nginx1對該頭訊息的應答。也就是說,firefox把一部分body塞到header包裡。
Firefox的這種行為使同事注意到nginx裡設定的另一個緩衝區大小:client_header_buffer_size。原來此前他們設定了該值為128k,此為條件三 。
綜合以上現象,就有了初步推斷:對於IE的請求,nginx把body只放到body的緩衝區處理,所以不受header的緩衝區大小的影響,而對於firefox的請求,nginx可能會把body放到header的緩衝區處理,所以,分別設定header、body緩衝區為128k、8k/16k的時候,POST 30k的圖片能夠成功而POST 200k的圖片返回500錯誤,分別設定header、body緩衝區為128k、256k的時候,POST 200k的圖片也能成功。
如何驗證這個結論呢?究竟什麼情況下body資料會放到header緩衝區處理呢?
“有問題,看日誌”是一個好習慣。但是預設情況下,nginx記錄的日誌比較簡單,不能滿足要求,需要這樣開啟除錯日誌功能:
編譯nginx,configure時使用--with-debug開啟除錯資訊,然後make && make install
編輯nginx.conf,在server的error_log指令的檔名後面加上debug:
error_log logs/8085_error.log debug
使用firefox POST 30k左右的圖片時,擷取到的部分日誌如下:
70 2011/05/26 09:53:28 [debug] 23622#0: *33 http client request body preread 2398
71 2011/05/26 09:53:28 [debug] 23622#0: *33 http read client request body
72 2011/05/26 09:53:28 [debug] 23622#0: *33 recv: fd:3 5840 of 28645
73 2011/05/26 09:53:28 [debug] 23622#0: *33 http client request body recv 5840
74 2011/05/26 09:53:28 [debug] 23622#0: *33 http client request body rest 22805
按這幾行的關鍵字,可以搜尋到對應的函式為src/http/ngx_http_request_body.c 的ngx_http_read_client_request_body 和ngx_http_do_read_client_request_body。前者會把預讀的body(在原始碼裡,作者把被塞進http頭訊息包裡的那部分body稱為preread,即預讀的body)暫存到header緩衝區,而只要這塊header緩衝區足夠大,足以容納剩下的body的時候,會呼叫後者把它們也一起讀進來。於是,上面30k左右的圖片就能穿透過去,看上去不可思議的事情就這樣發生了。
簡單地分析一下相關原始碼。
在這裡開始正式讀取body。IE的請求,preread為零,而Firefox的請求,preread非零:
- 110 preread = r->header_in->last - r->header_in->pos;
- 111
- 112 if (preread) {
- …
- 166 rb->rest = r->headers_in.content_length_n - preread;
- 167
- 168 if (rb->rest <= (off_t) (b->end - b->last)) {
- 169
- 170 /* the whole request body may be placed in r->header_in */
- 171
- 172 rb->to_write = rb->bufs;
- 173
- 174 r->read_event_handler = ngx_http_read_client_request_body_handler;
- 175
- 176 return ngx_http_do_read_client_request_body(r);
- 177 }
在168行有個條件判斷,rb->rest是未讀body的剩餘長度,b->end – b->last就是空餘的緩衝區大小。當header緩衝區不夠大時,顯然是不會跑到上面176行那裡去的,而是會掉到下面,重新根據client_body_buffer_size的大小分配緩衝區處理。於是,200k那麼大的圖片就被擋住了。而30k左右的圖片,在設定了比較大的client_header_buffer_size的時候是可以過去的。
IE的請求會跑到這裡:
- 181 } else {
- 182 b = NULL;
- 183 rb->rest = r->headers_in.content_length_n;
- 184 next = &rb->bufs;
- 185 }
- 186
前面處理不完的都跑到這裡,用了兩次client_body_buffer_size,意思是剩餘的內容不超過緩衝區大小的1.25倍,一次讀完(1.25可能是經驗值吧),否則,按緩衝區大小讀取。
- 187 size = clcf->client_body_buffer_size;
- 188 size += size >> 2;
- 189
- 190 if (rb->rest < size) {
- 191 size = (ssize_t) rb->rest;
- 192
- 193 if (r->request_body_in_single_buf) {
- 194 size += preread;
- 195 }
- 196
- 197 } else {
- 198 size = clcf->client_body_buffer_size;
- 199
- 200 /* disable copying buffer for r->request_body_in_single_buf */
- 201 b = NULL;
- 202 }
- 203
- 204 rb->buf = ngx_create_temp_buf(r->pool, size);
- 205 if (rb->buf == NULL) {
- 206 return NGX_HTTP_INTERNAL_SERVER_ERROR;
- 207 }
- …
- 236 return ngx_http_do_read_client_request_body(r);
其實這樣的處理流程也是無可厚非的,遇到body比較小,剛好header緩衝區又能夠放得下,不用白不用,是不是?
最後,整理一下出現這個問題需要的條件。值得注意的是,目前各種版本的nginx都有這個現象(0.7.68、0.8.54、1.0.2都有)
1) client_body_temp設定為不可訪問,使得沒有許可權寫臨時檔案
2) client_body_buffer_size使用預設設定,8k或者16k
3) client_header_buffer_size設定得比較大