Docker 容器日誌分析

遊戲不存在發表於2019-03-24

檢視容器日誌

先使用 docker run -it --rm -d -p 80:80 nginx:1.15.8-alpine 命令啟動一個nginx容器。如果沒有異常,會得到容器ID如 d2408a7931c95a3a83ffeca2fba887763cf925a67890ef3be4d9ff838aa25b00 的長串。再使用 curl -i http://127.0.0.1 訪問服務,確認nginx容器正常啟動執行。最後使用 docker logs -f d24 檢視容器的日誌輸出,大概如下:

172.17.0.1 - - [24/Mar/2019:03:51:21 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-"
複製程式碼

一般來說使用容器ID的前3位即可

以上就是我們檢視容器日誌的日常方法了,非常簡單實用。

容器日誌檔案儲存

容器的日誌會以json檔案方式儲存在本地磁碟,可以使用下面方式檢視檔案路徑 docker inspect d42 | grep Log 可以找到:

"LogPath": "/var/lib/docker/containers/d2408a7931c95a3a83ffeca2fba887763cf925a67890ef3be4d9ff838aa25b00/d2408a7931c95a3a83ffeca2fba887763cf925a67890ef3be4d9ff838aa25b00-json.log",
複製程式碼

注意1:mac上沒有/var/lib/docker目錄 ,因為docker for mac的運作方式不一樣,最好使用linux系統練習。

注意2: 如果LogPath內容為空,大概是因為docker engine版本,升級docker版本能到docker-ce 18.09.3

檢視 d2408a7931c95a3a83ffeca2fba887763cf925a67890ef3be4d9ff838aa25b00-json.log 檔案,可以看到:

{"log":"172.17.0.1 - - [24/Mar/2019:03:51:21 +0000] \"GET / HTTP/1.1\" 200 612 \"-\" \"curl/7.29.0\" \"-\"\r\n","stream":"stdout","time":"2019-03-24T03:51:21.982476951Z"}
複製程式碼

這條資訊的log欄位內容和之前通過 docker logs 命令檢視的內容一致。

容器日誌會跟隨容器生命週期,容器銷燬後日志也會銷燬。使用 docker stop 24 關停測試的nginx服務。因為容器啟動使用時候用了 --rm 引數,關停後會自動清理刪除,所以會發現 /var/lib/docker/containers/d2408a7931c95a3a83ffeca2fba887763cf925a67890ef3be4d9ff838aa25b00 目錄不存在了,相應的日誌檔案也就刪除了。

容器日誌檔案滾動策略

docker容器日誌預設寫入json檔案,線上上執行時候會有磁碟寫滿的風險。可以調整策略,讓其進行滾動。修改/etc/docker/daemon.json(如果沒有就手工建立一個),增加下面內容:

{
  "log-opts": {
    "max-size": "1m",
    "max-file": "3"
  }
}
複製程式碼

修改完成後重啟docker服務:

systemctl daemon-reload
systemctl restart docker.service
複製程式碼

測試一下新的日誌策略,使用下面的命令建立一個容器:

docker run -d --rm alpine:3.6 sh -c "while true; do echo hello world; usleep 10; done"
複製程式碼

這個alpine容器就是每隔10微秒輸出hello world,保持高頻度輸出,快速生產日誌檔案。

注:shell中的時間控制
1、sleep : 預設為秒。
sleep 1s 表示延遲一秒  
sleep 1m 表示延遲一分鐘  
sleep 1h 表示延遲一小時  
sleep 1d 表示延遲一天    
  
2、usleep : 預設以微秒。  
1s = 1000ms = 1000000us
複製程式碼

按照前文中檢視日誌檔案的方法

# pwd
/var/lib/docker/containers/aa3307f5b42770319129e126122be123cfd8e0ebe1c412371ad27e62faa007e3
# ls -lah
total 2.6M
drwx------ 4 root root 4.0K Mar 24 16:22 .
drwx------ 3 root root 4.0K Mar 24 16:21 ..
-rw-r----- 1 root root 647K Mar 24 16:22 aa3307f5b42770319129e126122be123cfd8e0ebe1c412371ad27e62faa007e3-json.log
-rw-r----- 1 root root 977K Mar 24 16:22 aa3307f5b42770319129e126122be123cfd8e0ebe1c412371ad27e62faa007e3-json.log.1
-rw-r----- 1 root root 977K Mar 24 16:21 aa3307f5b42770319129e126122be123cfd8e0ebe1c412371ad27e62faa007e3-json.log.2
複製程式碼

很容易發現,日誌檔案的策略就是維持3個1m大小檔案存在,和我們設定保持一致。

測試完成後,記得使用docker stop aa3 清理測試現場,max-size也可以按照真實需求調整大小。

nginx容器日誌

瞭解docker容器的日誌策略後,再看看常用的容器是如何處理的。先看看nginx容器。

首先 docker run -it --rm -d -p 80:80 nginx:1.15.8-alpine 建立一個nginx容器,然後 docker exec -it b6d sh 進入容器,檢視/etc/nginx/nginx.conf可以看到下面內容:

error_log  /var/log/nginx/error.log warn;
access_log  /var/log/nginx/access.log  main;
複製程式碼

也就是nginx會將錯誤日誌和訪問日誌寫入對應的日誌檔案。繼續檢視/var/log/nginx目錄:

/var/log/nginx # ls -lah
total 0
drwxr-xr-x    2 root     root          39 Mar  4 07:54 .
drwxr-xr-x    3 root     root          18 Mar  4 07:54 ..
lrwxrwxrwx    1 root     root          11 Jan 31 23:32 access.log -> /dev/stdout
lrwxrwxrwx    1 root     root          11 Jan 31 23:32 error.log -> /dev/stderr
複製程式碼

這就發現奧祕了,access.log檔案會通過軟連結重定向到標準輸出,而錯誤日誌error.log則會重定向標準錯誤。這樣使用docker log命令就可以看到nginx的訪問日誌了。

為了進一步驗證,檢視nginx dockerfile檔案,其中有:

    # forward request and error logs to docker log collector
	&& ln -sf /dev/stdout /var/log/nginx/access.log \
	&& ln -sf /dev/stderr /var/log/nginx/error.log
複製程式碼

可見nginx映象建立時候就定義好了日誌檔案的輸出。

同樣使用docker stop 524清理現場,以後就不再介紹清理這一步驟了。

mysql容器日誌

啟動一個mysql容器

docker run --rm -e MYSQL_ROOT_PASSWORD=123456 mysql:5.7
複製程式碼

不難看到mysql容器日誌輸出, 擷取其中片段如下:

Initializing database
2019-03-24T08:48:19.102726Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-03-24T08:48:20.241459Z 0 [Warning] InnoDB: New log files created, LSN=45790
2019-03-24T08:48:20.414933Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2019-03-24T08:48:20.509897Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 935a6ee7-4e11-11e9-b135-0242ac110002.
2019-03-24T08:48:20.519148Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2019-03-24T08:48:20.519843Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2019-03-24T08:48:24.066683Z 1 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066730Z 1 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066740Z 1 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066756Z 1 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066761Z 1 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066772Z 1 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066814Z 1 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-03-24T08:48:24.066822Z 1 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
Database initialized
Initializing certificates
Generating a RSA private key
複製程式碼

檢視mysql Dockerfile 檔案,可以知道mysql映象啟動入口在entrypoint.sh,從指令碼中發現:

echo 'Initializing database'
"$@" --initialize-insecure
echo 'Database initialized'
複製程式碼

這樣就是mysql容器啟動時候的輸出對應起來了。entrypoint.sh比較複雜,主要功能就是啟動mysqld,並將日誌輸出,因為不是本文重點,就不詳細介紹了。

總結

  1. docker容器預設輸出到本地json檔案,並且可以對其進行大小和數量控制。
  2. 應用容器日誌可以先生成日誌檔案,然後將應用日誌檔案軟連線到標準輸出,比如nginx;也可以在啟動時候直接將日誌列印到標準輸出,比如mysql。

參考連結

Docker 日誌都在哪裡?怎麼收集?

JSON File logging driver

docker mysql

相關文章