docker pull 和 push 的性能分析

Share To Facebook Twitter

从单docker daemon和registry之间的pull/push出发,分析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层的优化已经意义不大。

(责任编辑:IT)

Posted in 未分类

发表评论