Bug 1771335

Summary: S2I build from authenticated registry can't pull image
Product: OpenShift Container Platform Reporter: David Simansky <dsimansk>
Component: BuildAssignee: Gabe Montero <gmontero>
Status: CLOSED ERRATA QA Contact: wewang <wewang>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 4.3.0CC: adam.kaplan, aos-bugs, gmontero, maschmid, wzheng
Target Milestone: ---Keywords: NeedsTestCase
Target Release: 4.3.0   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-01-23 11:12:18 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:
Embargoed:
Attachments:
Description Flags
reproducer with --build-loglevel=6 none

Description David Simansky 2019-11-12 08:00:33 UTC 
Description of problem:
We have a testsuite the uses pull secret and image located in registry.redhat.io. 
The same image + secret is passing without issues on 4.2.x. but on the nightlies of 4.3.x the build always fails during image pull.
I've tried several times with different secrets to make sure it is not issue with invalid token.

The secret is linked to `deployer` and `builder` SAs exactly by the following procedure:
https://docs.openshift.com/container-platform/4.2/openshift_images/managing-images/using-image-pull-secrets.html#images-allow-pods-to-reference-images-from-secure-registries_using-image-pull-secrets

From the debug log I see that secret is found, tried and pull failed. Executing exactly the same scenario with same values on 4.2.x instance passes without issues.


Build log:
===
Caching blobs under "/var/cache/blobs".
Warning: Pull failed, retrying in 5s ...
Warning: Pull failed, retrying in 5s ...
Warning: Pull failed, retrying in 5s ...
error: build error: After retrying 2 times, Pull image still failed due to error: unable to retrieve auth token: invalid username/password: unauthorized: Please login to the Red Hat Registry using your Customer Portal credentials. Further instructions can be found here: https://access.redhat.com/RegistryAuthentication

===


Build log with loglevel 5:
===
I1112 07:55:48.117992       1 builder.go:329] openshift-builder v4.3.0-201911081629+d2059b4-dirty
I1112 07:55:48.121376       1 builder.go:330] redacted build: {"kind":"Build","apiVersion":"build.openshift.io/v1","metadata":{"name":"vertx-http-example-2","namespace":"dsimansk","selfLink":"/apis/build.openshift.io/v1/namespaces/dsimansk/builds/vertx-http-example-2","uid":"9fe9f914-4531-4e12-bfab-b56d0202cbec","resourceVersion":"25385","creationTimestamp":"2019-11-12T07:55:36Z","labels":{"app":"vertx-http-example","buildconfig":"vertx-http-example","openshift.io/build-config.name":"vertx-http-example","openshift.io/build.start-policy":"Serial"},"annotations":{"openshift.io/build-config.name":"vertx-http-example","openshift.io/build.number":"2"},"ownerReferences":[{"apiVersion":"build.openshift.io/v1","kind":"BuildConfig","name":"vertx-http-example","uid":"91aae132-b0a9-4543-97bf-277eb4a24eda","controller":true}]},"spec":{"serviceAccount":"builder","source":{"type":"Git","git":{"uri":"https://github.com/openshift-vertx-examples/vertx-http-example.git"}},"strategy":{"type":"Source","sourceStrategy":{"from":{"kind":"DockerImage","name":"registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745"},"pullSecret":{"name":"xtf-pull-secret"},"env":[{"name":"BUILD_LOGLEVEL","value":"5"}]}},"output":{"to":{"kind":"DockerImage","name":"image-registry.openshift-image-registry.svc:5000/dsimansk/vertx-http-example:latest"},"pushSecret":{"name":"builder-dockercfg-hmxkj"}},"resources":{},"postCommit":{},"nodeSelector":null,"triggeredBy":[{"message":"Manually triggered"}]},"status":{"phase":"New","outputDockerImageReference":"image-registry.openshift-image-registry.svc:5000/dsimansk/vertx-http-example:latest","config":{"kind":"BuildConfig","namespace":"dsimansk","name":"vertx-http-example"},"output":{}}}
Caching blobs under "/var/cache/blobs".
I1112 07:55:48.327322       1 util_linux.go:56] found cgroup parent kubepods-besteffort-podb10aeeda_91f5_4cf3_a10c_409c6f40bdf6.slice
I1112 07:55:48.327360       1 builder.go:337] Running build with cgroup limits: api.CGroupLimits{MemoryLimitBytes:92233720368547, CPUShares:0, CPUPeriod:0, CPUQuota:0, MemorySwap:92233720368547, Parent:"kubepods-besteffort-podb10aeeda_91f5_4cf3_a10c_409c6f40bdf6.slice"}
I1112 07:55:48.327555       1 sti.go:157] Found git source info: git.SourceInfo{Ref:"master", CommitID:"71ef48965c062a04a5bdaac9b1641ccc9e6034a0", Date:"Fri Sep 20 11:00:47 2019 -0600", AuthorName:"Rodney Russ", AuthorEmail:"rdruss", CommitterName:"GitHub", CommitterEmail:"noreply", Message:"Merge pull request #91 from openshift-vertx-examples/dependabot/maven/io.fabri..", Location:"https://github.com/openshift-vertx-examples/vertx-http-example.git", ContextDir:""}
Local copy of "registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745" is not present.
I1112 07:55:48.328352       1 sti.go:232] Locating docker config paths for type PULL_DOCKERCFG_PATH
I1112 07:55:48.328379       1 sti.go:232] Getting docker config in paths : [/var/run/secrets/openshift.io/pull]
Explicitly pulling image registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745
Asked to pull fresh copy of "registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745".
I1112 07:55:48.328445       1 daemonless.go:61] looking for config.json at /var/run/secrets/openshift.io/pull/config.json
I1112 07:55:48.328474       1 cfg.go:163] error reading file: open /var/run/secrets/openshift.io/pull/config.json: no such file or directory
I1112 07:55:48.328494       1 daemonless.go:61] looking for .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
I1112 07:55:48.328663       1 daemonless.go:61] found valid .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
Warning: Pull failed, retrying in 5s ...
Asked to pull fresh copy of "registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745".
I1112 07:55:53.721964       1 daemonless.go:61] looking for config.json at /var/run/secrets/openshift.io/pull/config.json
I1112 07:55:53.722027       1 cfg.go:163] error reading file: open /var/run/secrets/openshift.io/pull/config.json: no such file or directory
I1112 07:55:53.722046       1 daemonless.go:61] looking for .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
I1112 07:55:53.722188       1 daemonless.go:61] found valid .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
Warning: Pull failed, retrying in 5s ...
Asked to pull fresh copy of "registry.redhat.io/openjdk/openjdk-11-rhel8@sha256:8d2177bdfc307bb023ce8b9438f2c1d4bd024fb15049a50e2672aa8c7fa69745".
I1112 07:55:59.013303       1 daemonless.go:61] looking for config.json at /var/run/secrets/openshift.io/pull/config.json
I1112 07:55:59.013354       1 cfg.go:163] error reading file: open /var/run/secrets/openshift.io/pull/config.json: no such file or directory
I1112 07:55:59.013370       1 daemonless.go:61] looking for .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
I1112 07:55:59.013509       1 daemonless.go:61] found valid .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
Warning: Pull failed, retrying in 5s ...
F1112 07:56:04.319459       1 helpers.go:114] error: build error: After retrying 2 times, Pull image still failed due to error: unable to retrieve auth token: invalid username/password: unauthorized: Please login to the Red Hat Registry using your Customer Portal credentials. Further instructions can be found here: https://access.redhat.com/RegistryAuthentication
===

Version-Release number of selected component (if applicable):
4.3.0-0.nightly-2019-11-12-013930


How reproducible:
Always

Steps to Reproduce:
1. Create pull secret for redhat.io
2. Link it to SAs by the linked proceedure
3. oc new-app registry.redhat.io/openjdk/openjdk-11-rhel8:latest~https://github.com/openshift-vertx-examples/vertx-http-example.git
4. Follow the build log

Actual results:
Build finishes with failure.

Expected results:
Build finishes with success and image can be deployed.
Comment 1 David Simansky 2019-11-12 08:04:47 UTC 
Furthermore other tests the configure DeploymentConfig to run on the base OpenJDK image from registry.redhat.io works without any issues. This seems to be only related to s2i build.
Comment 2 Adam Kaplan 2019-11-12 14:28:50 UTC 
Able to reproduce on 4.3.0-0.ci-2019-11-12-025736. Notable observations:

1. Pull secret created as a .dockercfg file [1]
2. Imagestream import from registry.redhat.io failed using the pull secret I provided. Same pull secret worked pulling images via docker (on macOS)
3. Pulling image locally got me past an initial error importing the imagestream tag.

[1] https://docs.openshift.com/container-platform/4.2/openshift_images/managing-images/using-image-pull-secrets.html#images-allow-pods-to-reference-images-from-secure-registries_using-image-pull-secrets
Comment 3 Gabe Montero 2019-11-12 18:34:07 UTC 
@Adam perhaps already on your radar, but this could be a containers/image problem.

Somewhat similar, I had to submit https://github.com/containers/image/pull/722 to get pulls to work with a .dockercfg based secret when getting the disconnected support for builds to work when trying to pull images from the image registry.

Perhaps something is amiss with .dockerconfigjson format as well.
Comment 4 Gabe Montero 2019-11-12 18:34:56 UTC 
Or maybe something was broken in containers/image in general with the last bump of c/image in openshift/builder
Comment 5 Adam Kaplan 2019-11-13 14:35:49 UTC 
There is something very broken with containers/image. I found that on macOS the .dockerconfigjson format is not correct for Docker CE.

Furthermore seeing this in the build when trying to pull from registry.redhat.io (log level 6):

```
I1113 14:25:09.074137       1 daemonless.go:61] looking for config.json at /var/run/secrets/openshift.io/pull/config.json
time="2019-11-13T14:25:09Z" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
time="2019-11-13T14:25:09Z" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
I1113 14:25:09.074215       1 cfg.go:163] error reading file: open /var/run/secrets/openshift.io/pull/config.json: no such file or directory
I1113 14:25:09.074233       1 daemonless.go:61] looking for .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
I1113 14:25:09.074333       1 daemonless.go:61] found valid .dockerconfigjson at /var/run/secrets/openshift.io/pull/.dockerconfigjson
time="2019-11-13T14:25:09Z" level=debug msg="reference \"[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\" does not resolve to an image ID"
time="2019-11-13T14:25:09Z" level=debug msg="registry \"registry.redhat.io\" is not listed in registries configuration \"/etc/containers/registries.conf\", assuming it's not blocked"
time="2019-11-13T14:25:09Z" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
time="2019-11-13T14:25:09Z" level=debug msg="parsed reference into \"[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
time="2019-11-13T14:25:09Z" level=debug msg="copying \"docker://registry.redhat.io/openjdk/openjdk-11-rhel8:latest\" to \"registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
time="2019-11-13T14:25:09Z" level=debug msg="starting to write to image \"containers-storage:[overlay@/var/lib/containers/storage+/var/run/containers/storage:overlay.imagestore=/var/lib/shared]registry.redhat.io/openjdk/openjdk-11-rhel8:latest\" using blob cache in \"/var/cache/blobs\""
time="2019-11-13T14:25:09Z" level=debug msg="reference rewritten from 'registry.redhat.io/openjdk/openjdk-11-rhel8:latest' to 'registry.redhat.io/openjdk/openjdk-11-rhel8:latest'"
time="2019-11-13T14:25:09Z" level=debug msg="Trying to pull \"registry.redhat.io/openjdk/openjdk-11-rhel8:latest\""
time="2019-11-13T14:25:09Z" level=debug msg="Credentials not found"
time="2019-11-13T14:25:09Z" level=debug msg="Using registries.d directory /etc/containers/registries.d for sigstore configuration"
time="2019-11-13T14:25:09Z" level=debug msg=" No signature storage configuration found for registry.redhat.io/openjdk/openjdk-11-rhel8:latest"
time="2019-11-13T14:25:09Z" level=debug msg="Looking for TLS certificates and private keys in /etc/docker/certs.d/registry.redhat.io"
time="2019-11-13T14:25:09Z" level=debug msg="GET https://registry.redhat.io/v2/"

```

I was able to do an oc debug on the build pod - the .dockerconfigjson had the correct pull secret for registry.redhat.io.

Given where we are in the release, I am going to revert the latest buildah+containers/image bump.
Comment 7 Adam Kaplan 2019-11-13 20:58:32 UTC 
@Gabe based on my analysis, we may an issue with some of the logic you added in [1]. It looks like we are passing in a dockercfg that the keyring can't look up.


[1] https://github.com/openshift/builder/pull/102
Comment 8 Adam Kaplan 2019-11-13 21:30:37 UTC 
Created attachment 1635945 [details]
reproducer with --build-loglevel=6
Comment 9 Gabe Montero 2019-11-14 16:46:10 UTC 
OK I have a patch that gets .dockerconfigjson based secrets working 

@David - can you confirm whether when you created the secret you did
1) oc create secret generic <pull_secret_name> \
    --from-file=.dockercfg=<path/to/.dockercfg> \
    --type=kubernetes.io/dockercfg

or 

2) oc create secret generic <pull_secret_name> \
    --from-file=.dockerconfigjson=<path/to/.docker/config.json> \
    --type=kubernetes.io/dockerconfigjson
Comment 10 David Simansky 2019-11-15 08:34:25 UTC 
@Gabe, yes it was `dockerconfigjson` format. 


Actually Customer Portal is generating Secret yaml in dockerconfigjson format.

```
apiVersion: v1
kind: Secret
metadata:
  name: rhoarqe-pull-secret
data:
  .dockerconfigjson: <REDACTED_TOKEN>
type: kubernetes.io/dockerconfigjson
```
Comment 12 wewang 2019-11-19 09:49:25 UTC 
Verified in version:
4.3.0-0.nightly-2019-11-18-175710

steps:
1.Create a bc from registry.redhat.io/rhscl/ruby-25-rhel7:latest image
kind: BuildConfig
apiVersion: v1
metadata:
  name: pullsecret-ruby
spec:
  source:
    git:
      uri: "https://github.com/openshift/ruby-hello-world"
  strategy:
    type: Source
    sourceStrategy:
      from:
        kind: DockerImage
        name: registry.redhat.io/rhscl/ruby-25-rhel7:latest

2. Create a pull secret 
   $ oc create secret generic test-secret --from-file=.dockerconfigjson=/root/.docker/config.json  --type=kubernetes.io/dockerconfigjson
3. Add  pull secret to bc 
   $ oc set build-secret --pull bc/pullsecret-ruby test-secret
4. Link builder to secret
   $oc secrets link builder test-secret
5. Create a build
[root@Desktop ~]# oc get builds
NAME                TYPE     FROM          STATUS     STARTED         DURATION
pullsecret-ruby-1   Source   Git@57073c0   Complete   4 minutes ago   1m45s
[root@Desktop ~]# oc logs -f build/pullsecret-ruby-1
Cloning "https://github.com/openshift/ruby-hello-world" ...
	Commit:	57073c041d103a412ff7d4a6e64b0ea7f77ea1b3 (Merge pull request #85 from wewang58/master)
	Author:	Ben Parees <bparees.github.com>
	Date:	Wed Nov 6 09:41:20 2019 -0500
Caching blobs under "/var/cache/blobs".
Getting image source signatures
Copying blob sha256:4a356d454a56b5710572b0d606627d6c9b066deaddea797d5fc8f647674386b9
Copying blob sha256:e5112e3dbe5c13c331015f062c932b60533e76b0c47c1b3707d8f80a86dacfd6
Copying blob sha256:1c9f515fc6ab2b7ebfcaffd8af681b68869d78a3b19c69e87c296363ab1bc2fe
Copying blob sha256:f1e961fe4c5192ab9f8e241a2efc674779623ac6a3ed49ee9a1a5b3b8425fe0d
Copying blob sha256:1d2c4ce43b78cb9a97ede7f19ad1406a43ee50532568bda660193e4a404b424f
Copying config sha256:edc7d7c4ec658c977fe573251e2a2b4ab79c99d8a9b2221721e90619fbacb555
Writing manifest to image destination
Storing signatures
Generating dockerfile with builder image registry.redhat.io/rhscl/ruby-25-rhel7:latest

also tried using command: oc create secret generic test-secret1 --from-file=.dockerconfigjson=/path to/config.json  --type=kubernetes.io/dockerconfigjson, it works.
Comment 15 errata-xmlrpc 2020-01-23 11:12:18 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:0062