摘要：最近在公司搭建一個基于的環境。的內核可以算是半個，依賴一些的容器相關的技術是不支持的，所以需要通過一個虛擬機運行來使用。于是和前端的同學，一起打開文件進行對比，但并沒有發現非常可疑的點。果然拿到的文件不再有末尾的亂碼。

最近在公司搭建一個基于 Docker 的 PHP 環境。

Docker 是一種容器技術，它可以提供一個隔離的環境，讓用戶的程序運行在一個完全隔離的虛擬的系統里，但 Docker 不是虛擬化，使用 Docker 可以在 Linux 上實現對于任意程序打包一次，到處運行。愿意接受安利的同學請移步 http://docker.io 。

Mac OS X 的內核可以算是半個 BSD，Docker 依賴一些的 Linux 容器相關的技術是 OS X 不支持的，所以需要通過一個虛擬機運行 Linux 來使用。

Docker 官方提供了一個方便 OS X 用戶的名為 "dockertoolbox" 的軟件包，包括這些內容：Docker CLI 客戶端 + Docker Machine CLI 管理界面 + Docker 倉庫 + VirtualBox + CoreOS + Kitematic （一個管理容器的GUI界面）。其中 CoreOS 是專門為虛擬化和容器技術設計的一個 Linux 發行版，精簡到了只剩容器和虛擬化需要的一些組件，所以性能非常好。

因為搭建 Docker PHP 環境的需要，已經把自己日常的業務開發遷移到了 Docker 上。如同往常一樣 git pull 拉下最新代碼，然后用瀏覽器打開正在開發中的項目，發現頁面上一片空白了，打開 Chrome 的控制臺，出現 Javascript 相關的報錯，并且在文件底部發現一連串的亂碼：

?????????????????

用 curl 拉下來然后用 vim 打開如下：

想當然的認為這可能是前端的鍋。于是和前端的同學，一起打開文件進行對比，但并沒有發現非常可疑的點。然后就覺得是 Tengine 產生的問題，因為切換到自己的真實的宿主機用 Nginx 1.8.0 訪問，沒有這個問題。切換到 Docker 的環境就有這個問題，而兩者的配置又幾乎是一樣的。

為了驗證是否是 Tengine 產生的問題，在 Docker 容器中依次安裝了 Tengine 2.1.2 (最新版), Nginx 1.9.10 (最新版), Nginx 1.8.0 (和宿主機相同)，均采用同一配置文件進行啟動，然而無一幸免的都還是出現了這個問題。

用排除法的話就可以認為問題可能在網絡通信或者是容器本體上了，嘗試先排除網絡的影響。繞過網絡的映射，直接在 Docker 的容器內部使用 curl 訪問來檢查，發現仍然存在這個問題，所以問題基本可以限定在容器上面。

為了驗證到底是不是容器產生的問題，在運維同學的建議下，第二天在虛擬機中特意安裝了一個 CentOS 6.7，以及安裝上公司運維組預編譯的 PHP 和 Tengine 的 RPM 包，然后采用完全一樣的配置，再次用 curl 訪問同樣的文件，沒有觀察到這個現象。所以確實可以確定已經是容器產生的問題。

盡管這里幾乎已經確定問題是哪里產生的，仍然陷入了死胡同，想要 Google 也不知道到底用什么關鍵詞。這個時候再試著在 Tengine 的日志中輸出的 HTTP Response 的消息體給記錄下來，在 Tengine 的配置中加上了這些代碼，用 Lua 來獲取 HTTP 的 Response，并記錄進日志：

log_format bodylog "$remote_addr - $remote_user [$time_local] "
      ""$request" $status $body_bytes_sent "
      ""$http_referer" "$http_user_agent" $request_time "
      "<"$request_body" >"$resp_body"";

lua_need_request_body on;
# 上面的配置加入 http {} 區域

  access_log /tmp/access.log bodylog;
  set $resp_body "";
  body_filter_by_lua "
    local resp_body = string.sub(ngx.arg[1], 1, 10000) #10000這里是sub函數的截取長度，可以按需要改大點
    ngx.ctx.buffered = (ngx.ctx.buffered or "") .. resp_body
    if ngx.arg[2] then
      ngx.var.resp_body = ngx.ctx.buffered
    end
  ";
# 上面的配置加入 server {} 區域
# 然后開啟對應的 access_log 即可

(來自 https://gist.github.com/morhekil/1ff0e902ed4de2adcb7a)

不過遺憾的是，訪問日志里面并沒有出現亂碼，而在 curl 的結果中，亂碼又確實還是存在的。

事已至此，想到可能需要對 Tengine 或者 Nginx 調試一下可能才能發現到底問題是出在什么地方了。所以想到了曾經跟蹤一個 PHP 的 Segmentation Fault 時用過的 strace，它可以打印出一個進程的所有的系統調用(System Call)，從而觀察程序大致上做了一些什么事情。于是馬上安裝上 strace，用帶 -f 的參數來運行 Tengine。

strace -f tengine

(# -f 參數是 follow forks，因為 Tengine / NGINX 的實際接受用戶請求的 Worker 是 fork 新建的進程)

然后照常用 curl 進行請求，獲得輸出：

...
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11,  
[pid 22865] <... epoll_wait resumed> {?} 0x7f0d78c9b000, 512, -1) = 1
[pid 22865] accept4(7, 0x7ffc7958c0b0, 0x7ffc7958c12c, SOCK_NONBLOCK) = 11
[pid 22865] epoll_ctl(9, EPOLL_CTL_ADD, 11, {...}) = 0
[pid 22865] epoll_wait(9, {?} 0x7f0d78c9b000, 512, 60000) = 1
[pid 22865] recvfrom(11, 0x7f0d78c3d800, 1024, 0, NULL, NULL) = 126
[pid 22865] stat(0x7f0d78c96f37, {...}) = 0
[pid 22865] open(0x7f0d78d6d3e0, O_RDONLY|O_NONBLOCK) = 12
[pid 22865] fstat(12, {...})            = 0
[pid 22865] pread(12, 0x7f0d78ef0000, 8857, 0) = 8857
[pid 22865] writev(11, [?] 0x7ffc7958b660, 1) = 286
[pid 22865] sendfile(11, 12, 0x7ffc7958b658, 8857) = 8857
[pid 22865] write(4, 0x7f0d78efc000, 9811) = 9811
[pid 22865] close(12)                   = 0
[pid 22865] setsockopt(11, SOL_TCP, TCP_NODELAY, 0x7ffc7958bfac, 4) = 0
[pid 22865] recvfrom(11, "", 1024, 0, NULL, NULL) = 0
[pid 22865] write(5, 0x7ffc7958b030, 87) = 87
[pid 22865] close(11)                   = 0
[pid 22865] epoll_wait(9,  
[pid 22866] <... epoll_wait resumed> {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
[pid 22866] epoll_wait(11, {}, 512, 100) = 0
...

(題外話: 這里還可以直觀的看到 epoll 實質上是一個死循環)

簡單解讀一下，前面的 epoll，read，write 相關的代碼應該都是從客戶端獲取請求，并且寫入日志，然后注意到了 sendfile。先前了解過 sendfile，它提供了從一個文件描述符到另一個文件描述符的高效的復制數據的方式。傳統的基于 read, write 的方式需要把數據在用戶空間進行操作，而 sendfile 是直接在內核空間進行的操作，所以性能要好。這時候就想到的就是 Tengine / Nginx 其實是有一個配置也就是 Sendfile On; 來激活 sendfile 來提供靜態文件的訪問速度的，所以就想到可能問題就是在這里，遂嘗試關閉。果然 curl 拿到的文件不再有末尾的亂碼。

至此問題是解決了，但是我們還是要來探究一下到底是為什么 sendfile 在這種場合下就不工作了。有了關鍵詞之后，問題就變得相對容易 Google 了。

首先找到了 Vargrant 也存在這個問題（因為默認也是基于 VirtualBox 的），并且在 Apache 和 NGINX 中都存在這個情況：

https://jeremyfelt.com/2013/01/08/clear-nginx-cache-in-vagrant/
https://github.com/mitchellh/vagrant/issues/351#issuecomment-1339640

然后就順藤摸瓜的找到了 VirtualBox 的官方的 ticket：

https://www.virtualbox.org/ticket/12597

原來是 VirtualBox 的共享目錄在使用 sendfile 來進行復制文件的時候，會錯誤的訪問到緩存的內容導致的。看了下報告 bug 的時間已經是2年前，果然 VirtualBox 畢竟不是 Oracle 親生的，這個問題并沒有得到重視，暫時還是先只能通過關掉 sendfile 來解決這個問題。

strace 真的是神器，不用調試就可以讓你看到程序運行的一些細節

Bug 有可能發生在你用到的任何組件里，對于一個全新的環境要有足夠的警惕性，不能想當然