Cache not working with assumed roles

[der-eismann]

We just setup your helper, unfortunately it seems like the cache is not used because for each pull a new registries entry is added. After executing the following line ten times, I have ten entries in the cache.json

$ docker pull 000000000000.dkr.ecr.eu-west-1.amazonaws.com/base-image:latest (x10)
$ cat .ecr/cache.json
{
  "Registries": {
    "eu-west-1-QVNJQVJDV0kzSTJPM05CVUE1RjXUHYzZjwCyBOmACZjs+EJ+-000000000000": {
      "AuthorizationToken": "abcde..",
      "RequestedAt": "2021-03-01T15:31:17.625780278+01:00",
      "ExpiresAt": "2021-03-02T02:31:17.608Z",
      "ProxyEndpoint": "https://000000000000.dkr.ecr.eu-west-1.amazonaws.com",
      "Service": "ecr"
    },
    "eu-west-1-QVNJQVJDV0kzSTJPMkhTNVFZWDTUHYzZjwCyBOmACZjs+EJ+-000000000000": {
      "AuthorizationToken": "abcde..",
      "RequestedAt": "2021-03-01T15:31:27.782053219+01:00",
      "ExpiresAt": "2021-03-02T02:31:27.765Z",
      "ProxyEndpoint": "https://000000000000.dkr.ecr.eu-west-1.amazonaws.com",
      "Service": "ecr"
    },
    "eu-west-1-QVNJQVJDV0kzSTJPNE9BU0FaUEfUHYzZjwCyBOmACZjs+EJ+-000000000000": {
      "AuthorizationToken": "abcde..",
      "RequestedAt": "2021-03-01T15:31:26.014890264+01:00",
      "ExpiresAt": "2021-03-02T02:31:25.998Z",
      "ProxyEndpoint": "https://000000000000.dkr.ecr.eu-west-1.amazonaws.com",
      "Service": "ecr"
    },
    "eu-west-1-QVNJQVJDV0kzSTJPNUQyNkRRTkfUHYzZjwCyBOmACZjs+EJ+-000000000000": {
      "AuthorizationToken": "abcde..",
      "RequestedAt": "2021-03-01T15:29:37.716101251+01:00",
      "ExpiresAt": "2021-03-02T02:29:37.697Z",
      "ProxyEndpoint": "https://000000000000.dkr.ecr.eu-west-1.amazonaws.com",
      "Service": "ecr"
    },
    "eu-west-1-QVNJQVJDV0kzSTJPNkVCQUE1VlXUHYzZjwCyBOmACZjs+EJ+-000000000000": {
      "AuthorizationToken": "abcde..",
      "RequestedAt": "2021-03-01T15:29:47.49652767+01:00",
      "ExpiresAt": "2021-03-02T02:29:47.48Z",
      "ProxyEndpoint": "https://000000000000.dkr.ecr.eu-west-1.amazonaws.com",
      "Service": "ecr"
    },
   ...
  },
  "Version": "1.0"
}
$ cat .ecr/logs/ecr-login.log
time="2021-03-01T15:29:37+01:00" level=debug msg="Retrieving credentials" region=eu-west-1 registry=000000000000 serverURL=000000000000.dkr.ecr.eu-west-1.amazonaws.com service=ecr
time="2021-03-01T15:29:37+01:00" level=debug msg="Checking file cache" registry=000000000000
time="2021-03-01T15:29:37+01:00" level=debug msg="Calling ECR.GetAuthorizationToken" registry=000000000000
time="2021-03-01T15:29:37+01:00" level=debug msg="Saving credentials to file cache" registry=000000000000 service=ecr
time="2021-03-01T15:29:44+01:00" level=debug msg="Retrieving credentials" region=eu-west-1 registry=000000000000 serverURL=000000000000.dkr.ecr.eu-west-1.amazonaws.com service=ecr
time="2021-03-01T15:29:44+01:00" level=debug msg="Checking file cache" registry=000000000000
time="2021-03-01T15:29:44+01:00" level=debug msg="Calling ECR.GetAuthorizationToken" registry=000000000000
time="2021-03-01T15:29:44+01:00" level=debug msg="Saving credentials to file cache" registry=000000000000 service=ecr
time="2021-03-01T15:29:47+01:00" level=debug msg="Retrieving credentials" region=eu-west-1 registry=000000000000 serverURL=000000000000.dkr.ecr.eu-west-1.amazonaws.com service=ecr
time="2021-03-01T15:29:47+01:00" level=debug msg="Checking file cache" registry=000000000000
time="2021-03-01T15:29:47+01:00" level=debug msg="Calling ECR.GetAuthorizationToken" registry=000000000000
time="2021-03-01T15:29:47+01:00" level=debug msg="Saving credentials to file cache" registry=000000000000 service=ecr
time="2021-03-01T15:31:17+01:00" level=debug msg="Retrieving credentials" region=eu-west-1 registry=000000000000 serverURL=000000000000.dkr.ecr.eu-west-1.amazonaws.com service=ecr
time="2021-03-01T15:31:17+01:00" level=debug msg="Checking file cache" registry=000000000000
time="2021-03-01T15:31:17+01:00" level=debug msg="Calling ECR.GetAuthorizationToken" registry=000000000000
time="2021-03-01T15:31:17+01:00" level=debug msg="Saving credentials to file cache" registry=000000000000 service=ecr
time="2021-03-01T15:31:20+01:00" level=debug msg="Retrieving credentials" region=eu-west-1 registry=000000000000 serverURL=000000000000.dkr.ecr.eu-west-1.amazonaws.com service=ecr
time="2021-03-01T15:31:20+01:00" level=debug msg="Checking file cache" registry=000000000000
time="2021-03-01T15:31:20+01:00" level=debug msg="Calling ECR.GetAuthorizationToken" registry=000000000000
time="2021-03-01T15:31:20+01:00" level=debug msg="Saving credentials to file cache" registry=000000000000 service=ecr
...

Since these were all for the same image from the same registry shouldn't the first cache entry be re-used until it expires? Or am I misunderstanding this? From the logs it looks like it is checking the cache but doesn't find a suitable entry. Since we use it on a build server I'm afraid that this file would get pretty huge quickly.

This is the .docker/config.json:

{
	"credHelpers": {
		"000000000000.dkr.ecr.eu-west-1.amazonaws.com": "ecr-login-wrapper"
	},
	"experimental": "enabled"
}

This is our wrapper script since I didn't see an easy option to set an environment variable that gets passed from Jenkins to Docker:

#!/bin/bash

export AWS_PROFILE=ecr-push

/usr/local/bin/docker-credential-ecr-login "$@"

We are also using Docker 20.10.

[der-eismann]

I have to add that I am assuming a role to get the credentials, I guess that's where it breaks because the AccessKeyID is changing on every request and the cache is relying on it. I'll disable the cache for now, but it would be great if someone could get this to work.

[der-eismann]

Closing because this seems kinda dead and we don't use it anymore