Bug 1466631 - SmartState analysis image fails on OpenShift due to registry authentication failure
SmartState analysis image fails on OpenShift due to registry authentication f...
Status: ASSIGNED
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: SmartState Analysis (Show other bugs)
5.8.0
Unspecified Unspecified
unspecified Severity high
: GA
: 5.8.2
Assigned To: Erez Freiberger
Gilad Shefer
container:smartstate
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2017-06-30 02:07 EDT by Siamak Sadeghianfar
Modified: 2017-08-07 04:27 EDT (History)
6 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: Container Management


Attachments (Terms of Use)

  None (edit)
Description Siamak Sadeghianfar 2017-06-30 02:07:06 EDT
Description of problem:

CloudForms 4.5 container is deployed on OpenShift 3.5. When running smartstate analysis, the image-inspector pod fails with:

2017/06/30 06:00:37 Pulling image 172.30.201.234:5000/coolstore-prod-48c1/inventory@sha256:b9b8231aff9ec534f8a38c907a7f31f1244344ed058b19403b9c8339ebe11a55
2017/06/30 06:00:37 Authentication with Default Empty Authentication failed: unauthorized: authentication required
2017/06/30 06:00:37 Authentication with /var/run/secrets/kubernetes.io/inspector-admin-secret-inspector-admin-dockercfg-35wl2/.dockercfg/172.30.201.234:5000 failed: manifest unknown: manifest unknown
2017/06/30 06:00:37 Authentication with /var/run/secrets/kubernetes.io/inspector-admin-secret-inspector-admin-dockercfg-35wl2/.dockercfg/docker-registry.default.svc:5000 failed: manifest unknown: manifest unknown
2017/06/30 06:00:37 Error inspecting image: Unable to pull docker image: <nil>

OpenShift version:
oc v3.5.5.15
kubernetes v1.5.2+43a9be4
features: Basic-Auth GSSAPI Kerberos SPNEGO

Image version:
registry.access.redhat.com/openshift3/image-inspector:2.1'

Image inspector command:
/usr/bin/image-inspector --chroot --image=172.30.201.234:5000/coolstore-prod-48c1/inventory@sha256:b9b8231aff9ec534f8a38c907a7f31f1244344ed058b19403b9c8339ebe11a55 --scan-type=openscap --serve=0.0.0.0:8080 --dockercfg=/var/run/secrets/kubernetes.io/inspector-admin-secret-inspector-admin-dockercfg-35wl2/.dockercfg
Comment 2 Federico Simoncelli 2017-07-04 11:00:46 EDT
Erez can you take a look at this? Thanks.
Comment 3 Erez Freiberger 2017-07-04 11:12:50 EDT
This is not due to authentication failure, it is due to the image not being in the registry (manifest unknown: manifest unknown).
If it was an authentication problem then all the authentications would have failed with "unauthorized: authentication required".
Comment 4 Federico Simoncelli 2017-07-04 11:15:16 EDT
(In reply to Erez Freiberger from comment #3)
> This is not due to authentication failure, it is due to the image not being
> in the registry (manifest unknown: manifest unknown).
> If it was an authentication problem then all the authentications would have
> failed with "unauthorized: authentication required".

So what should we do? Is it because we're requesting a wrong sha?
Can you continue debug/work on this until we find out if it's a real bug (=> fix) or if it's just an image that was deleted/pruned (nothing much for us other than probably return a more friendly error).

Thanks.
Comment 5 Siamak Sadeghianfar 2017-07-04 11:16:47 EDT
Why would CloudForms trigger an inspection on an image that doesn't exist in the registry?
Comment 6 Federico Simoncelli 2017-07-04 11:20:28 EDT
(In reply to Siamak Sadeghianfar from comment #5)
> Why would CloudForms trigger an inspection on an image that doesn't exist in
> the registry?

Because as anything else in the inventory the list of image is synced to the last refresh (few minutes old).
Comment 7 Erez Freiberger 2017-07-04 11:26:45 EDT
Siamak,
This image might also be an archived entity. Or in might have existed in the last inventory refresh but not when the scan initiated.
Can you check to see if the image is present or not in that registry?
Is it possible to provide the evm.log file from that time to see why was the scan initiated?
Comment 8 Brian Duffy 2017-07-27 08:28:07 EDT
Hi All, 

I have a similar issue to this.

1. The manifest was missing
2. Authentication with Default Empty Authentication failed

The first occurred because I copied images via skopeo from a different registry that were tagged by oc tag and only the image metadata was copied. I fixed this by pulling the image and tagging it correctly. But the authentication error persists.

>> oc version
oc v3.5.5.31
kubernetes v1.5.2+43a9be4
features: Basic-Auth GSSAPI Kerberos SPNEGO

Server https://bt-ose-master-internal-prod.inv.adroot.lgim.com:8443
openshift v3.5.5.31
kubernetes v1.5.2+43a9be4

CFME Version:            5.8.0.17

My registry is secured which is done by default in OSE 3.5. I also have a proxy but configured NO_PROXY for the internal registry in /etc/sysconfig/docker on all nodes. 

From the registry pod logs you can see "system:anonymous" is trying to pull the image layers for the image I am trying to scan.

"OpenShift access denied: User \"system:anonymous\" cannot get imagestreams/layers in project \"elasticsearch\""


>> oc logs manageiq-img-scan-26eff
2017/07/27 12:07:13 Pulling image 172.30.216.40:5000/elasticsearch/elasticsearch@sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac
2017/07/27 12:07:13 Authentication with Default Empty Authentication failed: unauthorized: authentication required

I would have thought that a user or service account with sufficient privileges should be used to pull the image layers? Like inspector-admin or management-admin?

>> oc logs  dc/docker-registry -n default | grep -i error | grep "12:07"

time="2017-07-27T12:07:13.567651262Z" level=error msg="error authorizing context: authorization header required" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=87a41631-fa27-4021-b594-d1c73c360146 http.request.method=GET http.request.remoteaddr="10.220.1.1:47856" http.request.uri="/v2/" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.logger=registry
time="2017-07-27T12:07:13.579535513Z" level=error msg="error authorizing context: authorization header required" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=869747a8-38ab-4619-9e0f-4affceac1be5 http.request.method=GET http.request.remoteaddr="10.220.1.1:47858" http.request.uri="/v2/" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.logger=registry
time="2017-07-27T12:07:13.604627796Z" level=error msg="OpenShift access denied: User \"system:anonymous\" cannot get imagestreams/layers in project \"elasticsearch\"" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=0b17e89d-fe06-4217-b48f-79355e166d36 http.request.method=GET http.request.remoteaddr="10.220.1.1:47862" http.request.uri="/v2/elasticsearch/elasticsearch/manifests/sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.auth.user=anonymous openshift.logger=registry vars.name="elasticsearch/elasticsearch" vars.reference="sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac"
time="2017-07-27T12:07:13.604734978Z" level=error msg="error authorizing context: access denied" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=0b17e89d-fe06-4217-b48f-79355e166d36 http.request.method=GET http.request.remoteaddr="10.220.1.1:47862" http.request.uri="/v2/elasticsearch/elasticsearch/manifests/sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.logger=registry vars.name="elasticsearch/elasticsearch" vars.reference="sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac"
time="2017-07-27T12:07:13.619223322Z" level=error msg="error authorizing context: authorization header required" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=e3acbac2-949c-4b9b-afe0-c3392a44d66c http.request.method=GET http.request.remoteaddr="10.220.1.1:47864" http.request.uri="/v2/" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.logger=registry
time="2017-07-27T12:07:13.63046194Z" level=error msg="error authorizing context: authorization header required" go.version=go1.7.6 http.request.host="172.30.216.40:5000" http.request.id=a7783787-d0d6-4b2b-9114-3b8554b18d9a http.request.method=GET http.request.remoteaddr="10.220.1.1:47866" http.request.uri="/v2/" http.request.useragent="docker/1.12.6 go/go1.7.6 kernel/3.10.0-514.26.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(go-dockerclient)" instance.id=e19a3390-d6d2-432a-9eb2-950d7699bab9 openshift.logger=registry
Comment 9 Erez Freiberger 2017-07-27 08:41:30 EDT
Hi Brian,

ManageIQ is suppose to send the inspector-admin service account credentials to the pod for it to try to use for connecting to the registry. Can you please print the pod definition here so we can see if it is sent? (oc get pod manageiq-img-scan-26eff -o yaml)
Comment 10 Brian Duffy 2017-07-27 09:20:59 EDT
Hi Erez

This is the pod definition:

>> oc get po -o yaml
apiVersion: v1
items:
- apiVersion: v1
  kind: Pod
  metadata:
    annotations:
      manageiq.org/guid: ce715f74-67e6-11e7-bcb7-02edce72fd78
      manageiq.org/hostname: ieabvlxrcfmel01
      manageiq.org/image: 172.30.216.40:5000/elasticsearch/elasticsearch@sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac
      manageiq.org/jobid: f2f00b24-72cd-11e7-8e94-02edce72fd78
      openshift.io/scc: privileged
    creationTimestamp: 2017-07-27T13:17:54Z
    labels:
      manageiq.org: "true"
      name: manageiq-img-scan-f2f00
    name: manageiq-img-scan-f2f00
    namespace: management-infra
    resourceVersion: "1375771"
    selfLink: /api/v1/namespaces/management-infra/pods/manageiq-img-scan-f2f00
    uid: ffda66b4-72cd-11e7-add1-06db963df628
  spec:
    containers:
    - command:
      - /usr/bin/image-inspector
      - --chroot
      - --image=172.30.216.40:5000/elasticsearch/elasticsearch@sha256:e81a4c852b94003f6e5a2ddb5edc381d73a1c7f9b64a135c0cdf90e50deaeaac
      - --scan-type=openscap
      - --serve=0.0.0.0:8080
      - --dockercfg=/var/run/secrets/kubernetes.io/inspector-admin-secret-inspector-admin-dockercfg-7f298/.dockercfg
      image: docker-registry-default.btprod.openshift.inv.adroot.lgim.com/lgim-staging/image-inspector:2.1
      imagePullPolicy: Always
      name: image-inspector
      ports:
      - containerPort: 8080
        protocol: TCP
      resources: {}
      securityContext:
        privileged: true
      terminationMessagePath: /dev/termination-log
      volumeMounts:
      - mountPath: /var/run/docker.sock
        name: docker-socket
      - mountPath: /var/run/secrets/kubernetes.io/inspector-admin-secret-inspector-admin-dockercfg-7f298
        name: inspector-admin-secret
        readOnly: true
      - mountPath: /var/run/secrets/kubernetes.io/serviceaccount
        name: default-token-rvbs4
        readOnly: true
    dnsPolicy: ClusterFirst
    imagePullSecrets:
    - name: default-dockercfg-zg2r6
    nodeName: ip-10-240-64-82.inv.adroot.lgim.com
    restartPolicy: Never
    securityContext: {}
    serviceAccount: default
    serviceAccountName: default
    terminationGracePeriodSeconds: 30
    volumes:
    - hostPath:
        path: /var/run/docker.sock
      name: docker-socket
    - name: inspector-admin-secret
      secret:
        defaultMode: 420
        secretName: inspector-admin-dockercfg-7f298
    - name: default-token-rvbs4
      secret:
        defaultMode: 420
        secretName: default-token-rvbs4
  status:
    conditions:
    - lastProbeTime: null
      lastTransitionTime: 2017-07-27T13:17:54Z
      status: "True"
      type: Initialized
    - lastProbeTime: null
      lastTransitionTime: 2017-07-27T13:17:54Z
      message: 'containers with unready status: [image-inspector]'
      reason: ContainersNotReady
      status: "False"
      type: Ready
    - lastProbeTime: null
      lastTransitionTime: 2017-07-27T13:17:54Z
      status: "True"
      type: PodScheduled
    containerStatuses:
    - image: public.hostname.something.something/namespace/image-inspector:2.1
      imageID: ""
      lastState: {}
      name: image-inspector
      ready: false
      restartCount: 0
      state:
        waiting:
          reason: ContainerCreating
    hostIP: 10.240.64.82
    phase: Pending
    startTime: 2017-07-27T13:17:54Z
kind: List
metadata: {}
resourceVersion: ""
selfLink: ""
Comment 11 Erez Freiberger 2017-07-27 09:37:54 EDT
Hi Brian,

I noticed that you are using an image-inspector image from a non standard registry. Can you make sure that it is based on the latest version?
I am asking because this seems very similar to https://bugzilla.redhat.com/show_bug.cgi?id=1449742 to which we released a fix last month.

Erez
Comment 12 Brian Duffy 2017-07-27 09:56:42 EDT
Hi Erez,

It's the Red Hat official one just retagged and pushed to a difference namespace in OSE

>>  docker images | grep image-inspector
172.30.216.40:5000/openshift3/image-inspector                                                   2.1                 15fca2c49606        4 weeks ago         269.3 MB
registry.access.redhat.com/openshift3/image-inspector                                           2.1                 15fca2c49606        4 weeks ago         269.3 MB
172.30.216.40:5000/lgim-staging/image-inspector                                                 2.1                 15fca2c49606        4 weeks ago         269.3 MB
Comment 13 Erez Freiberger 2017-08-02 05:26:04 EDT
Brian,
Is it possible to also get logs from CFME ? I am thinking maybe something else is killing the pod before it gets to proceed.
Comment 14 Brian Duffy 2017-08-07 04:27:17 EDT
Hi Erez,

I'll take another look at it today and gather some logs. Apologies for the silence.

Note You need to log in before you can comment on or make changes to this bug.