How to measure Docker build steps duration?

BuildKit, which was experimental in 18.06 and generally available in 18.09, has this functionality built in. To configure the dockerd daemon with experimental mode, you can setup the daemon.json:

$ cat /etc/docker/daemon.json
{
  "experimental": true
}

Then you can enable BuildKit from the client side with an environment variable:

$ export DOCKER_BUILDKIT=1
$ docker build -t java-test:latest .
[+] Building 421.6s (13/13) FINISHED
 => local://context (.dockerignore)                                                                           1.6s
 => => transferring context: 56B                                                                              0.3s
 => local://dockerfile (Dockerfile)                                                                           2.0s
 => => transferring dockerfile: 895B                                                                          0.4s
 => CACHED docker-image://docker.io/tonistiigi/copy:v0.1.3@sha256:e57a3b4d6240f55bac26b655d2cfb751f8b9412d6f  0.1s
 => docker-image://docker.io/library/openjdk:8-jdk-alpine                                                     1.0s
 => => resolve docker.io/library/openjdk:8-jdk-alpine                                                         0.0s
 => local://context                                                                                           1.7s
 => => transferring context: 6.20kB                                                                           0.4s
 => docker-image://docker.io/library/openjdk:8-jre-alpine                                                     1.3s
 => => resolve docker.io/library/openjdk:8-jre-alpine                                                         0.0s
 => /bin/sh -c apk add --no-cache maven                                                                      61.0s
 => copy /src-0/pom.xml java/pom.xml                                                                          1.3s
 => /bin/sh -c mvn dependency:go-offline                                                                    339.4s
 => copy /src-0 java                                                                                          0.9s
 => /bin/sh -c mvn package -Dmaven.test.skip=true                                                            10.2s
 => copy /src-0/gs-spring-boot-docker-0.1.0.jar java/app.jar                                                  0.8s
 => exporting to image                                                                                        1.2s
 => => exporting layers                                                                                       1.0s
 => => writing image sha256:d57028743ca10bb4d0527a294d5c83dd941aeb1033d4fe08949a135677846179                  0.1s
 => => naming to docker.io/library/java-test:latest                                                           0.1s

There’s also an option to disable the tty console output which generates output more suitable for scripting with each section having a start, stop, and duration:

$ docker build -t java-test:latest --progress plain .                                                                                                                         

#1 local://dockerfile (Dockerfile)                                                      
#1       digest: sha256:da721b637ea85add6e26070a48520675cefc2bed947c626f392be9890236d11b
#1         name: "local://dockerfile (Dockerfile)"      
#1      started: 2018-09-05 19:30:53.899809093 +0000 UTC
#1    completed: 2018-09-05 19:30:53.899903348 +0000 UTC
#1     duration: 94.255µs
#1      started: 2018-09-05 19:30:53.900069076 +0000 UTC
#1 transferring dockerfile: 38B done
#2 ...              

#2 local://context (.dockerignore)  
#2       digest: sha256:cbf55954659905f4d7bd2fc3e5e52d566055eecd94fd7503565315022d834c21
#2         name: "local://context (.dockerignore)"       
#2      started: 2018-09-05 19:30:53.899624016 +0000 UTC
#2    completed: 2018-09-05 19:30:53.899695455 +0000 UTC
#2     duration: 71.439µs
#2      started: 2018-09-05 19:30:53.899839335 +0000 UTC
#2    completed: 2018-09-05 19:30:54.359527504 +0000 UTC
#2     duration: 459.688169ms                                                            
#2 transferring context: 34B done                                


#1 local://dockerfile (Dockerfile)
#1    completed: 2018-09-05 19:30:54.592304408 +0000 UTC
#1     duration: 692.235332ms


#3 docker-image://docker.io/tonistiigi/copy:v0.1.3@sha256:e57a3b4d6240f55ba...           
#3       digest: sha256:39386c91e9f27ee70b2eefdee12fc8a029bf5edac621b91eb5f3e6001d41dd4f
#3         name: "docker-image://docker.io/tonistiigi/copy:v0.1.3@sha256:e57a3b4d6240f55bac26b655d2cfb751f8b9412d6f7bb1f787e946391fb4b21b"
#3      started: 2018-09-05 19:30:54.731749377 +0000 UTC 
#3    completed: 2018-09-05 19:30:54.732013326 +0000 UTC
#3     duration: 263.949µs


#5 docker-image://docker.io/library/openjdk:8-jdk-alpine
#5       digest: sha256:d680c6a82813d080081fbc3c024d21ddfa7ff995981cc7b4bfafe55edf80a319
#5         name: "docker-image://docker.io/library/openjdk:8-jdk-alpine"
#5      started: 2018-09-05 19:30:54.731483638 +0000 UTC
#5    completed: 2018-09-05 19:30:54.732480345 +0000 UTC
#5     duration: 996.707µs


#4 docker-image://docker.io/library/openjdk:8-jre-alpine
#4       digest: sha256:9ed31df4e6731a1718ea93bfa77354ad1ea2d1625c1cb16e2087d16d0b84bd00
#4         name: "docker-image://docker.io/library/openjdk:8-jre-alpine"                
#4      started: 2018-09-05 19:30:54.73176516 +0000 UTC
#4    completed: 2018-09-05 19:30:54.732603067 +0000 UTC
#4     duration: 837.907µs                              


#7 local://context
#7       digest: sha256:efe765161a29e2bf7a41439cd2e6656fcf6fa6bc97da825ac9b5a0d8adecf1ac
#7         name: "local://context"
#7      started: 2018-09-05 19:30:54.73178732 +0000 UTC
#7    completed: 2018-09-05 19:30:54.731880943 +0000 UTC
#7     duration: 93.623µs
#7      started: 2018-09-05 19:30:54.792740019 +0000 UTC
#7 transferring context: 473B done
#7    completed: 2018-09-05 19:30:55.059008345 +0000 UTC
#7     duration: 266.268326ms


#9 /bin/sh -c mvn dependency:go-offline
#9       digest: sha256:2197672cd7a44d93e0dba40aa00d7ef41f8680226d91f469d1c925646bdc8d6d
#9         name: "/bin/sh -c mvn dependency:go-offline"
#9      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#9    completed: 2018-09-05 19:30:55.203449147 +0000 UTC
#9     duration: 0s
#9       cached: true


#10 copy /src-0 java
#10       digest: sha256:36cf252c34be098731bd8c5fb3f273f9c1437a5f74a65a3555d71150c2092fa7
#10         name: "copy /src-0 java"
#10      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#10    completed: 2018-09-05 19:30:55.203449147 +0000 UTC
#10     duration: 0s
#10       cached: true

#11 /bin/sh -c mvn package -Dmaven.test.skip=true
#11       digest: sha256:390464b1fdc7a4c833b3476033d95b7714e22bcbfd018469e97b04781cb41532
#11         name: "/bin/sh -c mvn package -Dmaven.test.skip=true"
#11      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#11    completed: 2018-09-05 19:30:55.203449147 +0000 UTC
#11     duration: 0s
#11       cached: true


#12 copy /src-0/gs-spring-boot-docker-0.1.0.jar java/app.jar
#12       digest: sha256:a7d60191a720f80de72a77ebe0d4bd1b0fd55d44e623661e80916b7fd1952076
#12         name: "copy /src-0/gs-spring-boot-docker-0.1.0.jar java/app.jar"
#12      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#12    completed: 2018-09-05 19:30:55.203555216 +0000 UTC
#12     duration: 106.069µs
#12       cached: true


#6 /bin/sh -c apk add --no-cache maven
#6       digest: sha256:db505db5e418f195c7bad3a710ad40bec3d91d47ff11a6f464b3ae37af744e7d
#6         name: "/bin/sh -c apk add --no-cache maven"
#6      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#6    completed: 2018-09-05 19:30:55.203449147 +0000 UTC
#6     duration: 0s
#6       cached: true


#8 copy /src-0/pom.xml java/pom.xml
#8       digest: sha256:f032d4ff111c6ab0efef1a4e37d2467fffe43f48a529b8d56291ec81f96296ab
#8         name: "copy /src-0/pom.xml java/pom.xml"
#8      started: 2018-09-05 19:30:55.203449147 +0000 UTC
#8    completed: 2018-09-05 19:30:55.203449147 +0000 UTC
#8     duration: 0s
#8       cached: true


#13 exporting to image
#13       digest: sha256:d536dc2895c30fbde898bb4635581350a87c21f3695913ba21850a73d31422d9
#13         name: "exporting to image"
#13      started: 2018-09-05 19:30:55.203674127 +0000 UTC
#13 exporting layers done
#13 writing image sha256:d57028743ca10bb4d0527a294d5c83dd941aeb1033d4fe08949a135677846179 0.1s done
#13 naming to docker.io/library/java-test:latest
#13    completed: 2018-09-05 19:30:55.341300051 +0000 UTC
#13     duration: 137.625924ms
#13 naming to docker.io/library/java-test:latest 0.0s done

Leave a Comment