Bug 1375580

Summary: Source-to-image build commits taking 20-30 seconds
Product: OpenShift Online Reporter: Steve Speicher <sspeiche>
Component: ContainersAssignee: Stefanie Forrester <dakini>
Status: CLOSED CURRENTRELEASE QA Contact: Bing Li <bingli>
Severity: medium Docs Contact:
Priority: medium    
Version: 3.xCC: abhgupta, aos-bugs, dakini, jokerman, mmccomas, zhezli
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-10-04 13:06:59 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Steve Speicher 2016-09-13 13:27:02 UTC
Description of problem:
When performing a S2I build, it is taking up to 50% of the total time to just 

Version-Release number of selected component (if applicable):
preview (prod) - 
OpenShift Master:
v3.2.1.15-8-gc402626
Kubernetes Master:
v1.2.0-36-g4a3f9c5

preview (int) -
OpenShift Master:
v3.3.0.30
Kubernetes Master:
v1.3.0+52492b4

How reproducible:
Grab either nodejs or java/tomcat builder images with stock sample.

Steps to Reproduce:
1. Add to project
2. Start build, with at least --build-loglevel=3
3. Observe log output for commit (see below)

Actual results:
commits taking 20-30 seconds

Expected results:
something 90% faster or better

Additional info:

It shows taking 30 seconds (3.2 prod):

I0912 10:19:20.430974       1 docker.go:734] Committing container with dockerOpts: {Container:23c8b3deeeee6953ee08d70e8703565cc0ec1e920cafca163dbbcde454651975 Repository:sspeiche-test1/nodejs-mongodb-example-12 Tag:f43e7718 Message: Author: Run:0xc208642540}, config: {Hostname: Domainname: User:1001 Memory:0 MemorySwap:0 MemoryReservation:0 KernelMemory:0 CPUShares:0 CPUSet: AttachStdin:false AttachStdout:false AttachStderr:false PortSpecs:[] ExposedPorts:map[] StopSignal: Tty:false OpenStdin:false StdinOnce:false Env:[OPENSHIFT_BUILD_NAME=nodejs-mongodb-example-12 OPENSHIFT_BUILD_NAMESPACE=sspeiche-test1 OPENSHIFT_BUILD_SOURCE=https://github.com/sspeiche/nodejs-ex.git] Cmd:[/usr/libexec/s2i/run] DNS:[] Image: Volumes:map[] VolumeDriver: VolumesFrom: WorkingDir: MacAddress: Entrypoint:[] NetworkDisabled:false SecurityOpts:[] OnBuild:[] Mounts:[] Labels:map[summary:Platform for building and running Node.js 4 applications io.openshift.build.commit.id:0b6b5459bfd309fe9320206294a4b33c353e18c2 io.openshift.build.commit.ref:master com.redhat.deployments-dir:/opt/app-root/src Build_Host:rcm-img-docker02.build.eng.bos.redhat.com Name:rhscl/nodejs-4-rhel7 build-date:2016-07-28T14:04:18.079386Z io.openshift.tags:builder,nodejs,nodejs4 io.openshift.build.commit.date:Sat Sep 10 18:28:47 2016 -0400 io.openshift.build.commit.author:sspeiche <sspeiche> com.redhat.dev-mode:DEV_MODE:false io.s2i.scripts-url:image:///usr/libexec/s2i io.openshift.build.image:172.30.47.227:5000/sspeiche-test1/nodejs-mongodb-example@sha256:cefc215a45e16a2b451f3f3e426948a47e73ed455d513df88240168182d6e61d distribution-scope:public com.redhat.build-host:rcm-img-docker02.build.eng.bos.redhat.com io.openshift.build.source-location:https://github.com/sspeiche/nodejs-ex.git vcs-type:git io.openshift.s2i.scripts-url:image:///usr/libexec/s2i BZComponent:rh-nodejs4-docker io.openshift.expose-services:8080:http io.k8s.description:Platform for building and running Node.js 4 applications io.k8s.display-name:sspeiche-test1/nodejs-mongodb-example-12:f43e

I0912 10:19:50.932043       1 sti.go:334] Successfully built sspeiche-test1/nodejs-mongodb-example-12:f43e7718


A separate run on 3.3 preview (int) showing ~ 20 seconds. This is a big chunk/% of time for the overall process. Is this commit always going to be this slow? Seems odd it is 5x slower than pushing the image.

I0913 08:50:54.163106       1 docker.go:882] Committing container with dockerOpts: {Container:d87c49582c410709daaf1a9f6fb88f5b994534e625ff0b72a9d2a98af5f59a1e Repository:sspeiche-test1/njs-9 Tag:b27c1fa6 Message: Author: Run:0xc820417c00}, config: {Hostname: Domainname: User:1001 Memory:0 MemorySwap:0 MemoryReservation:0 KernelMemory:0 CPUShares:0 CPUSet: AttachStdin:false AttachStdout:false AttachStderr:false PortSpecs:[] ExposedPorts:map[] StopSignal: Tty:false OpenStdin:false StdinOnce:false Env:[OPENSHIFT_BUILD_NAME=njs-9 OPENSHIFT_BUILD_NAMESPACE=sspeiche-test1 OPENSHIFT_BUILD_SOURCE=https://github.com/openshift/nodejs-ex.git OPENSHIFT_BUILD_REFERENCE=master BUILD_LOGLEVEL=3] Cmd:[/usr/libexec/s2i/run] DNS:[] Image: Volumes:map[] VolumeDriver: VolumesFrom: WorkingDir: MacAddress: Entrypoint:[container-entrypoint] NetworkDisabled:false SecurityOpts:[] OnBuild:[] Mounts:[] Labels:map[Release:11.6 distribution-scope:public io.openshift.expose-services:8080:http io.openshift.build.image:registry.access.redhat.com/rhscl/nodejs-4-rhel7@sha256:5f480b1beecff69f00d18ecb8398640a6671669f02dd79f69ec9bbb6a2cd7b09 io.s2i.scripts-url:image:///usr/libexec/s2i vcs-ref:df6b7f906ffa40284184f8497893c7c021a3a55a io.openshift.build.source-location:https://github.com/openshift/nodejs-ex.git io.openshift.tags:builder,nodejs,nodejs4 Version:4 Vendor:Red Hat, Inc. com.redhat.dev-mode.port:DEBUG_PORT:5858 Authoritative_Registry:registry.access.redhat.com Name:rhscl/nodejs-4-rhel7 io.k8s.display-name:sspeiche-test1/njs-9:b27c1fa6 com.redhat.build-host:rcm-img-docker02.build.eng.bos.redhat.com com.redhat.dev-mode:DEV_MODE:false io.openshift.s2i.scripts-url:image:///usr/libexec/s2i Build_Host:rcm-img-docker02.build.eng.bos.redhat.com vcs-type:git io.openshift.build.commit.ref:master summary:Platform for building and running Node.js 4 applications architecture:x86_64 com.redhat.deployments-dir:/opt/app-root/src io.openshift.build.commit.message:add an alternate http address for the tests to execute on (#60) io.openshift.build.commit.author:Ionut Palade <PI-Victor.github.com> BZComponent:rh-nodejs4-docker io.k8s.description:Platform for building and running Node.js 4 applications Architecture:x86_64 build-date:2016-07-28T14:04:18.079386Z io.openshift.build.commit.id:0e748ed33864936b67494050e69840e6dafc8ece io.openshift.build.commit.date:Mon Aug 1 16:47:07 2016 +0200]}

I0913 08:51:15.273508       1 postexecutorstep.go:362] Executing step: report success

Comment 1 Stefanie Forrester 2016-09-13 18:12:20 UTC
I talked with Mike Fiedler who suggested this may be something Ops can fix by upgrading our EBS storage to io1 (right now it's gp2). 

Also, if docker is pushing every layer each time (instead of just the modified ones), then we might need to upgrade to docker-1.10.3-46.el7.10.x86_64 or higher to get a fix for this bug https://bugzilla.redhat.com/show_bug.cgi?id=1368024.

Comment 3 Abhishek Gupta 2016-09-20 22:30:21 UTC
The gp2 to io1 ebs volume type switch is going to be handled via a card on the ops board. The updated docker version is already installed in INT and will be upgraded in production as part of the 3.3 upgrade in devpreview prod.

Comment 4 Li Zhe 2016-09-21 05:22:03 UTC
Testing with nodejs on INT env.
I0920 23:33:57.338677       1 docker.go:882] Committing container with dockerOpts: {Container:ed0e23a11966cb1a85e01fadfcfcd91645bf80747fd4934c1d9fcc3eff99bb86 Repository:test11/test11-2 Tag:11682836 Message: Author: Run:0xc8201a9500}, config: {Hostname: Domainname: User:1001 Memory:0 MemorySwap:0 MemoryReservation:0 KernelMemory:0 CPUShares:0 CPUSet: AttachStdin:false AttachStdout:false AttachStderr:false PortSpecs:[] ExposedPorts:map[] StopSignal: Tty:false OpenStdin:false StdinOnce:false Env:[OPENSHIFT_BUILD_NAME=test11-2 OPENSHIFT_BUILD_NAMESPACE=test11 OPENSHIFT_BUILD_SOURCE=https://github.com/openshift/nodejs-ex.git OPENSHIFT_BUILD_REFERENCE=master BUILD_LOGLEVEL=3] Cmd:[/usr/libexec/s2i/run] DNS:[] Image: Volumes:map[] VolumeDriver: VolumesFrom: WorkingDir: MacAddress: Entrypoint:[container-entrypoint] NetworkDisabled:false SecurityOpts:[] OnBuild:[] Mounts:[] Labels:map[com.redhat.dev-mode:DEV_MODE:false io.openshift.expose-services:8080:http io.openshift.build.commit.message:Adds NodeJS/MongoDB template with persistent storage. (#64) Architecture:x86_64 io.k8s.description:Platform for building and running Node.js 4 applications io.k8s.display-name:test11/test11-2:11682836 vcs-type:git io.openshift.build.commit.date:Tue Sep 20 09:12:04 2016 -0400 Release:11.6 build-date:2016-07-28T14:04:18.079386Z BZComponent:rh-nodejs4-docker io.openshift.build.source-location:https://github.com/openshift/nodejs-ex.git com.redhat.deployments-dir:/opt/app-root/src Authoritative_Registry:registry.access.redhat.com Version:4 summary:Platform for building and running Node.js 4 applications com.redhat.dev-mode.port:DEBUG_PORT:5858 distribution-scope:public architecture:x86_64 Name:rhscl/nodejs-4-rhel7 io.s2i.scripts-url:image:///usr/libexec/s2i io.openshift.tags:builder,nodejs,nodejs4 io.openshift.build.commit.id:9457131bdbd399d1242ec7f4b2fa4fd4fcb5b05b io.openshift.s2i.scripts-url:image:///usr/libexec/s2i io.openshift.build.image:registry.access.redhat.com/rhscl/nodejs-4-rhel7@sha256:5f480b1beecff69f00d18ecb8398640a6671669f02
dd79f69ec9bbb6a2cd7b09 io.openshift.build.commit.author:Jacob Lucky <jlucky> io.openshift.build.commit.ref:master Vendor:Red Hat, Inc. com.redhat.build-host:rcm-img-docker02.build.eng.bos.redhat.com vcs-ref:df6b7f906ffa40284184f8497893c7c021a3a55a Build_Host:rcm-img-docker02.build.eng.bos.redhat.com]}
I0920 23:34:06.345399 1 postexecutorstep.go:362] Executing step: report success

Comment 5 Li Zhe 2016-09-21 05:24:44 UTC
As for java/tomcat, due to BZ1371995 https://bugzilla.redhat.com/show_bug.cgi?id=1371395, I can not verify it now.

Comment 6 Bing Li 2016-09-21 05:44:09 UTC
Build commits take 5s-10s in our tests in INT:

atomic-openshift-3.3.0.31-1.git.0.aede597.el7.x86_64
docker-1.10.3-46.el7.10.x86_64
kernel-3.10.0-327.28.2.el7.x86_64