1. 程式人生 > >nginx 報500 Internal Server Error

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非零:

  1. 110     preread = r->header_in->last - r->header_in->pos;  
  2. 111  
  3. 112     if (preread) {  
  4. …  
  5. 166         rb->rest = r->headers_in.content_length_n - preread;  
  6. 167  
  7. 168         if (rb->rest <= (off_t) (b->end - b->last)) {  
  8. 169  
  9. 170             /* the whole request body may be placed in r->header_in */
  10. 171  
  11. 172             rb->to_write = rb->bufs;  
  12. 173  
  13. 174             r->read_event_handler = ngx_http_read_client_request_body_handler;  
  14. 175  
  15. 176             return ngx_http_do_read_client_request_body(r);  
  16. 177         }  


在168行有個條件判斷,rb->rest是未讀body的剩餘長度,b->end – b->last就是空餘的緩衝區大小。當header緩衝區不夠大時,顯然是不會跑到上面176行那裡去的,而是會掉到下面,重新根據client_body_buffer_size的大小分配緩衝區處理。於是,200k那麼大的圖片就被擋住了。而30k左右的圖片,在設定了比較大的client_header_buffer_size的時候是可以過去的。

IE的請求會跑到這裡:

  1. 181     } else {  
  2. 182         b = NULL;  
  3. 183         rb->rest = r->headers_in.content_length_n;  
  4. 184         next = &rb->bufs;  
  5. 185     }  
  6. 186  


前面處理不完的都跑到這裡,用了兩次client_body_buffer_size,意思是剩餘的內容不超過緩衝區大小的1.25倍,一次讀完(1.25可能是經驗值吧),否則,按緩衝區大小讀取。

  1. 187     size = clcf->client_body_buffer_size;  
  2. 188     size += size >> 2;  
  3. 189  
  4. 190     if (rb->rest < size) {  
  5. 191         size = (ssize_t) rb->rest;  
  6. 192  
  7. 193         if (r->request_body_in_single_buf) {  
  8. 194             size += preread;  
  9. 195         }  
  10. 196  
  11. 197     } else {  
  12. 198         size = clcf->client_body_buffer_size;  
  13. 199  
  14. 200         /* disable copying buffer for r->request_body_in_single_buf */
  15. 201         b = NULL;  
  16. 202     }  
  17. 203  
  18. 204     rb->buf = ngx_create_temp_buf(r->pool, size);  
  19. 205     if (rb->buf == NULL) {  
  20. 206         return NGX_HTTP_INTERNAL_SERVER_ERROR;  
  21. 207     }  
  22. …  
  23. 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設定得比較大