Hide Forgot
Description of problem: When I manually kick off a build, I get a long delay (pending state) before the build is running. Once it starts running, it takes an expected amount of time. Version-Release number of selected component (if applicable): OpenShift Online Dev Preview (prod) OpenShift Master: v3.3.0.33 Kubernetes Master: v1.3.0+52492b4 How reproducible: Create project and app, I used nodejs-ex with defaults. Repeat the build process a number of times, it occurred on my 13th build. Unlucky 13 maybe? Expected results: To take <5s to from the time I click "start build" to when the build is running. Additional info: Hard to see from 'oc describe' (but I witnessed it a couple times from the UI) Events: FirstSeen LastSeen Count From SubobjectPath Type Reason Message --------- -------- ----- ---- ------------- -------- ------ ------- 1h 1h 1 {default-scheduler } Normal Scheduled Successfully assigned njs-13-build to ip-172-31-10-162.ec2.internal 1h 1h 1 {kubelet ip-172-31-10-162.ec2.internal} spec.containers{sti-build} Normal Pulling pulling image "registry.ops.openshift.com/openshift3/ose-sti-builder:v3.3.0.33" 1h 1h 1 {kubelet ip-172-31-10-162.ec2.internal} spec.containers{sti-build} Normal Pulled Successfully pulled image "registry.ops.openshift.com/openshift3/ose-sti-builder:v3.3.0.33" 1h 1h 1 {kubelet ip-172-31-10-162.ec2.internal} spec.containers{sti-build} Normal Created Created container with docker id e460f8d10a8a 1h 1h 1 {kubelet ip-172-31-10-162.ec2.internal} spec.containers{sti-build} Normal Started Started container with docker id e460f8d10a8a Vital pieces from events json: { "count": 1, "firstTimestamp": "2016-10-04T17:13:42Z", "involvedObject": { "apiVersion": "v1", "kind": "Pod", "name": "njs-13-build", "namespace": "sspeiche", "resourceVersion": "205130796", "uid": "e67288f1-8a55-11e6-8a06-0ebeb1070c7f" }, "lastTimestamp": "2016-10-04T17:13:42Z", "message": "Successfully assigned njs-13-build to ip-172-31-10-162.ec2.internal", "metadata": { "creationTimestamp": "2016-10-04T17:13:42Z", "name": "njs-13-build.147a637e679fd732", "namespace": "sspeiche", "resourceVersion": "205130799", "selfLink": "/api/v1/namespaces/sspeiche/events/njs-13-build.147a637e679fd732", "uid": "e6761e5f-8a55-11e6-8a06-0ebeb1070c7f" }, "reason": "Scheduled", "source": { "component": "default-scheduler" }, "type": "Normal" }, { "count": 1, "firstTimestamp": "2016-10-04T17:14:39Z", "involvedObject": { "apiVersion": "v1", "fieldPath": "spec.containers{sti-build}", "kind": "Pod", "name": "njs-13-build", "namespace": "sspeiche", "resourceVersion": "205130798", "uid": "e67288f1-8a55-11e6-8a06-0ebeb1070c7f" }, "lastTimestamp": "2016-10-04T17:14:39Z", "message": "pulling image \"registry.ops.openshift.com/openshift3/ose-sti-builder:v3.3.0.33\"", "metadata": { "creationTimestamp": "2016-10-04T17:14:39Z", "name": "njs-13-build.147a638bacfc8b88", "namespace": "sspeiche", "resourceVersion": "205132635", "selfLink": "/api/v1/namespaces/sspeiche/events/njs-13-build.147a638bacfc8b88", "uid": "086f9934-8a56-11e6-ba92-0e63b9c1c48f" }, "reason": "Pulling", "source": { "component": "kubelet", "host": "ip-172-31-10-162.ec2.internal" }, "type": "Normal" }, { "count": 1, "firstTimestamp": "2016-10-04T17:14:40Z", "involvedObject": { "apiVersion": "v1", "fieldPath": "spec.containers{sti-build}", "kind": "Pod", "name": "njs-13-build", "namespace": "sspeiche", "resourceVersion": "205130798", "uid": "e67288f1-8a55-11e6-8a06-0ebeb1070c7f" }, "lastTimestamp": "2016-10-04T17:14:40Z", "message": "Successfully pulled image \"registry.ops.openshift.com/openshift3/ose-sti-builder:v3.3.0.33\"", "metadata": { "creationTimestamp": "2016-10-04T17:14:40Z", "name": "njs-13-build.147a638bd065c8a3", "namespace": "sspeiche", "resourceVersion": "205132707", "selfLink": "/api/v1/namespaces/sspeiche/events/njs-13-build.147a638bd065c8a3", "uid": "08ca47cd-8a56-11e6-ba92-0e63b9c1c48f" }, "reason": "Pulled", "source": { "component": "kubelet", "host": "ip-172-31-10-162.ec2.internal" }, "type": "Normal" }, { "count": 1, "firstTimestamp": "2016-10-04T17:14:41Z", "involvedObject": { "apiVersion": "v1", "fieldPath": "spec.containers{sti-build}", "kind": "Pod", "name": "njs-13-build", "namespace": "sspeiche", "resourceVersion": "205130798", "uid": "e67288f1-8a55-11e6-8a06-0ebeb1070c7f" }, "lastTimestamp": "2016-10-04T17:14:41Z", "message": "Created container with docker id e460f8d10a8a", "metadata": { "creationTimestamp": "2016-10-04T17:14:41Z", "name": "njs-13-build.147a638c0f9bcf2c", "namespace": "sspeiche", "resourceVersion": "205132782", "selfLink": "/api/v1/namespaces/sspeiche/events/njs-13-build.147a638c0f9bcf2c", "uid": "096c0b06-8a56-11e6-ba92-0e63b9c1c48f" }, "reason": "Created", "source": { "component": "kubelet", "host": "ip-172-31-10-162.ec2.internal" }, "type": "Normal" }, { "count": 1, "firstTimestamp": "2016-10-04T17:14:41Z", "involvedObject": { "apiVersion": "v1", "fieldPath": "spec.containers{sti-build}", "kind": "Pod", "name": "njs-13-build", "namespace": "sspeiche", "resourceVersion": "205130798", "uid": "e67288f1-8a55-11e6-8a06-0ebeb1070c7f" }, "lastTimestamp": "2016-10-04T17:14:41Z", "message": "Started container with docker id e460f8d10a8a", "metadata": { "creationTimestamp": "2016-10-04T17:14:41Z", "name": "njs-13-build.147a638c2265b4d6", "namespace": "sspeiche", "resourceVersion": "205132800", "selfLink": "/api/v1/namespaces/sspeiche/events/njs-13-build.147a638c2265b4d6", "uid": "099c1e1e-8a56-11e6-ba92-0e63b9c1c48f" }, "reason": "Started", "source": { "component": "kubelet", "host": "ip-172-31-10-162.ec2.internal" }, "type": "Normal" }
From the time that the pod is assigned to the node til the time it starts pulling the image, it's about 1 minute. It seems like the node is taking its time with creating the container.
(In reply to Steve Speicher from comment #0) > Description of problem: > When I manually kick off a build, I get a long delay (pending state) before > the build is running. Once it starts running, it takes an expected amount of > time. Correction, stuck in "New". Hit it again with build #30.
What was the creation time for the pod? I see the delay from scheduling until kubelet acknowleding the pod was scheduled. Not much I can do about the image pull time. I am wondering if you saw an additional delay from point of pod creation to actual scheduling occurring.
@Derek, I don't have the pod info anymore. JSON above is all I have unless dakini has more logs from her end.
Hi Steve, Is this still happening?
(In reply to Brenton Leanhardt from comment #5) > Hi Steve, > > Is this still happening? I'm not seeing it anymore. What did you do?
I don't think anyone has done anything yet. Just trying to get an idea if this bug is reproducible or not or if we should close it.