這是五個小時與一個字符的戰鬥html
是的,做爲一個程序員,你每每發現,有的時候你花費了數小時,數天,甚至數星期來查找問題,但最終可能只花費了數秒,改動了數行,甚至幾個字符就解決了問題。此次給你們分享一個困擾了我好久,我花了五個小時才查找出問題緣由,最終只添加了一個字符解決了的問題。nginx
咱們的業務系統比較複雜,但最終提供給用戶的訪問接口比較單一,都是使用 Nginx 來作一個代理轉發,而這個代理轉發,每每須要匹配不少種不一樣類型的 URL 轉給不一樣的服務。這就使得咱們的 Nginx 配置文件變得很複雜,粗略估計了下,咱們有近20個 upstream,有近60個 location 匹配。這些配置按照模塊分佈在不一樣的文件中,雖然複雜,可是仍然在咱們的努力下運行的良好。直到有一天,有位同事給我反映說偶爾有些 URL 會出現 404 的問題。一開始沒太在乎,由於他也說不許是哪種 URL 才遇到這個問題。程序員
後來,慢慢的查找,找到了一些規律,一開始只知道是 tomcat 那邊返回 404了,想到 Nginx 都代理給了 tomcat,一開始就懷疑是程序的問題,不會想到是 Nginx。web
我開始查找代碼的問題,我在本地的開發環境,嘗試了好久,我使用 8080 端口訪問,不論如何都是正確的結果,但是生產環境就是不行。而後我就聽信了某坑友同事的理論,重啓解決 95% 的問題,重裝解決 100%的問題,我嘗試重啓了 tomcat 和 Nginx,依然不行,而後是重裝,你猜結果如何????? ——想啥呢?固然也是不行!正則表達式
後來就開始懷疑是生產環境和開發環境的差別,去服務器上訪問 8080 端口,仍然是能夠的。但是一通過 Nginx 代理,就不行。這個時候纔開始懷疑是 Nginx 出了什麼問題。tomcat
Nginx 怎麼會出問題呢,業務系統中 URL 模式 /helloworld/* ,這樣的 URL 咱們都是統一處理的。怎麼會出現一些行,一些不行呢。問題表現爲 A URL (/helloworld/nn/hello/world)沒問題,而 B URL(/helloworld/ii/hello/world) 有問題。服務器
因此到目前爲止,基本能夠確定是 Nginx 的 location 上出了一些問題。app
因篇幅有限,爲了直面本次問題的核心,我再也不貼出完整的 Nginx 配置,我簡化這次問題的模型。請看以下 Nginx 配置,這是咱們以前的會致使問題的錯誤配置模型。curl
worker_processes 1; error_log logs/error.log; events { worker_connections 1024; } http { include mime.types; default_type application/octet-stream; log_format main '$remote_addr - $request_time - $remote_user [$time_local] "$request" ' '$status $body_bytes_sent "$http_referer" ' '"$http_user_agent" "$http_x_forwarded_for"'; access_log logs/access.log main; sendfile on; keepalive_timeout 65; gzip on; server { listen 80; server_name localhost; location / { root html; index index.html index.htm; } location = /helloworld { return 602; } location /helloworld { return 603; } ## 生產環境中以下兩個 location 在另一個文件中,經過 include 包含進來 location /ii { return 604; } location ~ /ii/[^\/]+/[^\/]+ { return 605; } ## location ~ ^/helloworld/(scripts|styles|images).* { return 606; } } }
注意,這裏有幾點須要說明一下,生產環境的 Nginx 服務器配置文件比這裏要複雜不少,並且是按模塊分佈在不一樣的文件中的。這裏簡化模型後,使用 Http 響應狀態碼 60x 來區分到底被哪一個 location 匹配到了。
我針對當時的狀況,作了大量嘗試,最終的簡化版本以下:測試
嘗試1:http://localhost/helloworld ==> 602 符合預期
嘗試2:http://localhost/helloworld/hello ==> 603 符合預期
嘗試3:http://localhost/ii ==> 604 符合預期
嘗試4:http://localhost/ii/oo ==> 604 符合預期
嘗試5:http://localhost/ii/pp/kk ==> 605 符合預期
嘗試6:http://localhost/ii/pp/kk/ll ==> 605 符合預期
嘗試7:http://localhost/helloworld/scripts/aaa.js ==> 606 符合預期
嘗試8:http://localhost/helloworld/ii/hello/world ==> 605 不符合預期,預期爲【603】
上面這些嘗試支持讀者自行試驗,Nginx 配置文件是完整可用的,我本地 Nginx 的版本是1.6.2
問題就在這裏:我這裏是過後,把這些匹配 location 標記成了不一樣的響應碼,才方便查找問題。當發現這個不符合預期後,我仍是難以理解,爲什麼我一個以 /helloworld 開頭的 URL 會被匹配到 605 這個以 /ii 開頭的 location 裏面來。在當時的生產環境中,以 /ii 的配置統一放在另一個文件中,這裏是很難直觀的察覺出來這個 /ii 跟訪問的 URL 裏面的 /ii 的關係。
我不得不從新編譯了 Nginx ,加上了調試參數,修改配置項,看調試日誌了。
這裏再也不講如何給 Nginx 加調試的編譯參數,可自行查看相關文檔。修改配置項很簡單,只須要在
error_log logs/error.log;
後面加上 debug 就能夠了。
打出詳細調試日誌後,訪問http://localhost/helloworld/ii/hello/world
我獲得了這樣的一段日誌(省略掉了先後無用的日誌,只保留有意義的一段):
2015/02/02 15:38:48 [debug] 5801#0: *60 http request line: "GET /helloworld/ii/hello/world HTTP/1.1" 2015/02/02 15:38:48 [debug] 5801#0: *60 http uri: "/helloworld/ii/hello/world" 2015/02/02 15:38:48 [debug] 5801#0: *60 http args: "" 2015/02/02 15:38:48 [debug] 5801#0: *60 http exten: "" 2015/02/02 15:38:48 [debug] 5801#0: *60 http process request header line 2015/02/02 15:38:48 [debug] 5801#0: *60 http header: "User-Agent: curl/7.37.1" 2015/02/02 15:38:48 [debug] 5801#0: *60 http header: "Host: localhost" 2015/02/02 15:38:48 [debug] 5801#0: *60 http header: "Accept: */*" 2015/02/02 15:38:48 [debug] 5801#0: *60 http header done 2015/02/02 15:38:48 [debug] 5801#0: *60 event timer del: 4: 1422862788055 2015/02/02 15:38:48 [debug] 5801#0: *60 rewrite phase: 0 2015/02/02 15:38:48 [debug] 5801#0: *60 test location: "/" 2015/02/02 15:38:48 [debug] 5801#0: *60 test location: "ii" 2015/02/02 15:38:48 [debug] 5801#0: *60 test location: "helloworld" 2015/02/02 15:38:48 [debug] 5801#0: *60 test location: ~ "/ii/[^\/]+/[^\/]+" 2015/02/02 15:38:48 [debug] 5801#0: *60 using configuration "/ii/[^\/]+/[^\/]+" 2015/02/02 15:38:48 [debug] 5801#0: *60 http cl:-1 max:1048576 2015/02/02 15:38:48 [debug] 5801#0: *60 rewrite phase: 2 2015/02/02 15:38:48 [debug] 5801#0: *60 http finalize request: 605, "/helloworld/ii/hello/world?" a:1, c:1 2015/02/02 15:38:48 [debug] 5801#0: *60 http special response: 605, "/helloworld/ii/hello/world?" 2015/02/02 15:38:48 [debug] 5801#0: *60 http set discard body 2015/02/02 15:38:48 [debug] 5801#0: *60 posix_memalign: 00007FC3BB816000:4096 @16 2015/02/02 15:38:48 [debug] 5801#0: *60 HTTP/1.1 605 Server: nginx/1.6.2 Date: Mon, 02 Feb 2015 07:38:48 GMT Content-Length: 0 Connection: keep-alive
能夠看到,Nginx 測試了幾回 location 匹配,最終選擇了~ "/ii/[^\/]+/[^\/]+"
這個做爲最終的匹配項。到這裏問題就徹底展示出來了,咱們原本的意思,是要以 /ii 開頭,後面有兩個或者更多的 / 分割的 URL 模型才匹配,可是這裏的正則表達式匹配寫的不夠精準,致使了匹配錯誤。正則表達式沒有限制必須從開頭匹配,因此纔會匹配到 /helloworld/ii/hello/world 這樣的 URL 。
解決辦法就是在這個正則表達式前面加上 ^ 來強制 URL 必須以 /ii 開頭才能匹配.
由/ii/[^\/]+/[^\/]+
變成^/ii/[^\/]+/[^\/]+
至此,這個坑被填上了,消耗的是五個小時和一個字符。
相信不少人在寫 Nginx 的location 的時候都會 location ~ /xxx 或者 location /iii 這樣簡單了事,可是我想說的是能儘可能精確就儘可能精確,不然出現問題的時候,很是難以查找。
有關 Nginx 的 location 匹配規則,能夠查看: http://nginx.org/en/docs/http/ngx_http_core_module.html
這個問題看似簡單,卻也隱含了很多問題,值得咱們深思。
計算機或者軟件出的問題每每是肯定的,你發現他捉摸不定的時候,每每是沒有觀察到問題點
追蹤一個問題,若是有一個必現方式,必定要緊追不捨,這就是所謂線索
當你實在是找不到問題所在的時候,要懷疑一下以前被本身排除掉的可能性
藉助各個組件的詳細調試日誌來查找問題,每每能獲得意想不到的效果
程序員的價值不是用行數,字數,提交數衡量的!