docker pull 和 push 的性能分析

0. 測試環境

基本架構：沒有docker index，全部操做發生在daemon和registry之間

鏡像：

# docker images --tree   
Warning: '--tree' is deprecated, it will be removed soon. See usage.
├─9247a3750813 Virtual Size: 85.1 MB
│ └─a92b1d9f0ca5 Virtual Size: 1.078 GB Tags: 10.180.156.6:5000/bigtest2:latest

網絡環境：docker daemon和registry之間爲千兆網絡，帶寬足夠大。

1. docker push 日誌分析及registry put對比測試

在客戶端作一次docker push的時候，觀察registry端日誌，刨去無關的一些日誌後，以下：

10.180.156.11 - - [02/Apr/2015:03:25:55 +0000] "GET /v2/ HTTP/1.1" 404 233 "-" "Go 1.1 package http"
10.180.156.11 - - [02/Apr/2015:03:25:55 +0000] "GET /v1/_ping HTTP/1.1" 200 2 "-" "Go 1.1 package http"
02/Apr/2015:03:25:55 +0000 DEBUG: args = {'namespace': 'library', 'repository': u'bigtest2'}
02/Apr/2015:03:25:55 +0000 ERROR: <?xml version="1.0" encoding="UTF-8"?>
10.180.156.11 - - [02/Apr/2015:03:25:55 +0000] "PUT /v1/repositories/bigtest2/ HTTP/1.1" 200 2 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:25:55 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
02/Apr/2015:03:25:55 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
02/Apr/2015:03:25:55 +0000 DEBUG: api_error: Image not found
10.180.156.11 - - [02/Apr/2015:03:25:55 +0000] "GET /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/json HTTP/1.1" 404 28 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:25:55 +0000 DEBUG: api_error: Image not found
10.180.156.11 - - [02/Apr/2015:03:25:55 +0000] "GET /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/json HTTP/1.1" 404 28 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:25:55 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
10.180.156.11 - - [02/Apr/2015:03:25:56 +0000] "PUT /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/json HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
===3秒===
02/Apr/2015:03:25:57 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
===34秒===
10.180.156.11 - - [02/Apr/2015:03:26:31 +0000] "PUT /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/layer HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:26:31 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
10.180.156.11 - - [02/Apr/2015:03:26:31 +0000] "PUT /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/checksum HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:26:31 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
10.180.156.11 - - [02/Apr/2015:03:26:32 +0000] "PUT /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/json HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
===6秒===
02/Apr/2015:03:26:37 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
===325秒===
10.180.156.11 - - [02/Apr/2015:03:32:02 +0000] "PUT /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/layer HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:32:02 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
10.180.156.11 - - [02/Apr/2015:03:32:03 +0000] "PUT /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/checksum HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:32:03 +0000 DEBUG: args = {'tag': u'latest', 'namespace': 'library', 'repository': u'bigtest2'}
02/Apr/2015:03:32:03 +0000 DEBUG: [put_tag] namespace=library; repository=bigtest2; tag=latest
10.180.156.11 - - [02/Apr/2015:03:32:03 +0000] "PUT /v1/repositories/bigtest2/tags/latest HTTP/1.1" 200 4 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:03:32:03 +0000 DEBUG: args = {'images': True, 'namespace': 'library', 'repository': u'bigtest2'}
10.180.156.11 - - [02/Apr/2015:03:32:03 +0000] "PUT /v1/repositories/bigtest2/images HTTP/1.1" 204 - "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"

能夠發現，對於一個2層的鏡像，整個push的時間能夠分紅幾段

操做	耗時	百分比
put json1	3s	0.8%
put layer1	34s	9.2%
put json2	6s	1.6%
put layer2	325s	87.6%
總耗時	371s	100%

也就是說，在作put layer1和put layer2時消耗了96.8%的時間。那麼，純的對registry服務作一樣文件的PUT操做，會消耗多少時間呢？

# time curl -X PUT  -H "Transfer-Encoding: chunked" --data-binary @layer-a92b1 "http://10.180.156.6:5000/v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/layer"
true
real	0m44.571s
user	0m0.302s
sys	0m1.341s

# time curl -X PUT  -H "Transfer-Encoding: chunked" --data-binary @layer-9247a "http://10.180.156.6:5000/v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/layer"
true
real	0m4.277s
user	0m0.029s
sys	0m0.130s

2. docker pull 日誌分析及registry get對比測試

相似上個節，繼續作pull的日誌分析

10.180.156.11 - - [02/Apr/2015:08:54:16 +0000] "GET /v2/ HTTP/1.1" 404 233 "-" "Go 1.1 package http"
10.180.156.11 - - [02/Apr/2015:08:54:16 +0000] "GET /v1/_ping HTTP/1.1" 200 2 "-" "Go 1.1 package http"
02/Apr/2015:08:54:16 +0000 DEBUG: args = {'namespace': 'library', 'repository': u'bigtest2'}
10.180.156.11 - - [02/Apr/2015:08:54:16 +0000] "GET /v1/repositories/bigtest2/images HTTP/1.1" 200 152 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:54:16 +0000 DEBUG: args = {'namespace': u'library', 'repository': u'bigtest2'}
02/Apr/2015:08:54:16 +0000 DEBUG: [get_tags] namespace=library; repository=bigtest2
10.180.156.11 - - [02/Apr/2015:08:54:16 +0000] "GET /v1/repositories/library/bigtest2/tags HTTP/1.1" 200 78 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:54:16 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
10.180.156.11 - - [02/Apr/2015:08:54:16 +0000] "GET /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/ancestry HTTP/1.1" 200 136 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:54:16 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
10.180.156.11 - - [02/Apr/2015:08:54:17 +0000] "GET /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/json HTTP/1.1" 200 619 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:54:17 +0000 DEBUG: args = {'image_id': u'9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f'}
===6秒===
10.180.156.11 - - [02/Apr/2015:08:54:23 +0000] "GET /v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/layer HTTP/1.1" 200 37124367 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:54:24 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
===42秒===
02/Apr/2015:08:55:06 +0000 DEBUG: api_error: Image not found
10.180.156.11 - - [02/Apr/2015:08:55:06 +0000] "GET /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/json HTTP/1.1" 404 28 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:55:06 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
10.180.156.11 - - [02/Apr/2015:08:55:06 +0000] "GET /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/json HTTP/1.1" 200 1172 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"
02/Apr/2015:08:55:07 +0000 DEBUG: args = {'image_id': u'a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5'}
===2秒===
10.180.156.11 - - [02/Apr/2015:08:56:08 +0000] "GET /v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/layer HTTP/1.1" 200 420084375 "-" "docker/1.5.0 go/go1.4.1 git-commit/a8a31ef kernel/3.13.0-32-generic os/linux arch/amd64"

能夠發現，對於一個2層的鏡像，整個pull的時間能夠分紅幾段

操做	耗時	百分比
get json1	6s	5.1%
get layer1	42s	36.2%
get json2	0s	0%
get layer2	2s	1.7%
總耗時	116s	100%

對比直接從registry上get測試

# time curl -X GET  -H "Transfer-Encoding: chunked" -o layer-9247a-down "http://10.180.156.6:5000/v1/images/9247a37508136a5fe916f4f87bfa2aa47f2edf8fc1a1ce787445b606d8fdbf9f/layer"
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 35.4M  100 35.4M    0     0  25.3M      0  0:00:01  0:00:01 --:--:-- 25.3M

real	0m1.409s
user	0m0.036s
sys	0m0.233s

# time curl -X GET  -H "Transfer-Encoding: chunked" -o layer-a92b1-down "http://10.180.156.6:5000/v1/images/a92b1d9f0ca59cefd024a5f2f2d23e2d617b3e67cc2363c94998006fa87e60e5/layer"
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  400M  100  400M    0     0  19.2M      0  0:00:20  0:00:20 --:--:-- 24.5M

real	0m20.771s
user	0m0.381s
sys	0m2.501s

3. 結論

從單個操做看，docker push/pull的50%以上的耗時在docker daemon，作分層、打tar包、checksum等。在這方面registry層的優化已經意義不大。