Image timestamps are incorrect

[mithrandi]

I'm not sure if this is a Docker registry issue or a Flux issue, but the "created" timestamp seems to be based off of the image layers. This means that if a newer build ends up containing the same content as an older build, it will appear to be an older image and Flux will not upgrade.

[mithrandi]

For example:

CONTROLLER                     CONTAINER  IMAGE                                         CREATED
default:deployment/matarisvan  trader     eu.gcr.io/decisive-cinema-167507/matarisvan
                                          '-> 513469a                                   07 Jan 18 14:08 UTC
                                              1932033                                   07 Jan 18 12:09 UTC
                                              271969a                                   07 Jan 18 12:09 UTC
                                              271969ad97c492fec8966d8d65d3a82abc4d2be9  07 Jan 18 12:09 UTC

271969ad97c492fec8966d8d65d3a82abc4d2be9 is an image that I just built:

        "Metadata": {                                              
            "LastTagTime": "2018-01-08T03:47:20.349896156+02:00"
        }                       

But since it is the same as an earlier build (I reverted some changes that I made), it looks older to Flux.

[squaremo]

Your diagnosis is correct: older flux (<v1.2), and in some circumstances newer flux, uses the timestamp of the topmost image layer as the image creation date.

The reason is that the backward-compatible (schema1) image manifests don't have a created date of their own; they just include some metadata on the image layers for backward-compatibility, which we can parse to get a created date. The new (schema2) image manifests do include* metadata of their own, which we can use directly.

(*More accurately: schema2 manifests include a digest which doubles as a pointer to a file which has the metadata.)

I'm surprised that you have this problem with eu.gcr.io though. Part of the impetus for #851, which added proper support for the new-style manifests among other things, was that GCR deprecated appeared to stop serving some schema1 manifests, possibly those that were rewritten (per https://docs.docker.com/registry/spec/manifest-v2-2/#backward-compatibility). Do you know what version of Docker you're using to push images to GCR?

[squaremo]

While I'm here, some oblique ways to fix this kind of thing would be:

1. use the git history of the image's source code to determine the order of images (needs a fair bit of development work to support this, and will require a bit of legwork for people to set up)
2. use version number order (no help here; but another alternative in general)

[mithrandi]

I'm running 17.12.0-ce now, but I might have been running 17.09.1-ce at the time that I ran into this bug (this is an image I've been building locally on my dev machine by hand).

[mithrandi]

It looks like the image is stored locally in a way that loses the identity of the exact tag:

mithrandi@lorien ~> docker inspect eu.gcr.io/decisive-cinema-167507/matarisvan:271969ad97c492fec8966d8d65d3a82abc4d2be9
[                              
    {                                                                                                                            
        "Id": "sha256:adbe673de18166c62e20f6be5a4126c784b372103917f72fe7c7ac68f5540d99",
        "RepoTags": [                                                                       
            "eu.gcr.io/decisive-cinema-167507/matarisvan:1932033",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:271969a",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:271969ad97c492fec8966d8d65d3a82abc4d2be9",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:c4336b7"
        ],                                                                                     
        "RepoDigests": [     
            "eu.gcr.io/decisive-cinema-167507/matarisvan@sha256:f902afab213b0f991f5b8131540b7b94bd69e3f30ccd95e336a0ef5c837ce764"
        ],                       
        "Parent": "sha256:a10c452d0fbc772337712a0cdb5cb366d44b6ec1434910574f97c4435ae106e7",
…

mithrandi@lorien ~> docker inspect eu.gcr.io/decisive-cinema-167507/matarisvan:1932033
[                              
    {                          
        "Id": "sha256:adbe673de18166c62e20f6be5a4126c784b372103917f72fe7c7ac68f5540d99",
        "RepoTags": [                                                               
            "eu.gcr.io/decisive-cinema-167507/matarisvan:1932033",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:271969a",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:271969ad97c492fec8966d8d65d3a82abc4d2be9",
            "eu.gcr.io/decisive-cinema-167507/matarisvan:c4336b7"
        ],                                                                                     
        "RepoDigests": [    
            "eu.gcr.io/decisive-cinema-167507/matarisvan@sha256:f902afab213b0f991f5b8131540b7b94bd69e3f30ccd95e336a0ef5c837ce764"
        ],                 
        "Parent": "sha256:a10c452d0fbc772337712a0cdb5cb366d44b6ec1434910574f97c4435ae106e7",
…

I suspect if I were building this in a regular CI environment where the old tags aren't around, then I would have avoided running into this.

[squaremo]

I'm running 17.12.0-ce now

OK right -- my hypothesis was that an old version of Docker somewhere was pushing schema1 manifests, so that's what flux was getting, and that's why it could only use the image layer created date. But the first bit isn't true -- Docker v17 will be pushing schema2 manifests.

I was pretty sure that GCR served schema2 manifests (see #780) if that's what you push to it. Surprising.

I did write a tool for getting more information about manifests, at one point, let me see if I can find it ..

[mithrandi]

Hmm, the GCR UI thinks it should be schema 2:

It seems like all the tags share the same manifest though.

[squaremo]

New hypothesis: the data we extract from the schema2 manifests is still not what you expected. Is 7 days ago as pictured about right, i.e,. is the gcr UI showing what you expect?

[squaremo]

Actually I can answer that for myself by looking at what you wrote above .. Can you get a more precise time stamp from the GCR UI, and is it 2018-01-08T03:47 or 07 Jan 18 12:09

[mithrandi]

It looks like flux and the GCR UI don't agree on the timestamp:

                                              1932033                                   07 Jan 18 12:09 UTC
                                              271969a                                   07 Jan 18 12:09 UTC
                                              271969ad97c492fec8966d8d65d3a82abc4d2be9  07 Jan 18 12:09 UTC
                                              c4336b7                                   07 Jan 18 12:09 UTC

And in the GCR UI:

Uploaded time
8 January 2018 at 03:47:25 UTC+2

I believe the Flux timestamps are the earliest build of that image that I made, and the GCR timestamp is the latest.

[squaremo]

I believe the Flux timestamps are the earliest build of that image that I made, and the GCR timestamp is the latest.

Looks like that to me too. So, now to figure out where GCR is getting its timestamp from ...

[squaremo]

Workaround for now, that may or may not be to your taste: make a minor change in the image build (e.g., by including a label of the git revision in the Dockerfile) and push it again.

[squaremo]

The essential problem is that the registry API (of any version to date) doesn't expose information about tags -- that's left to Docker, if you build locally, and to the implementation of the image registry.

In gcr.io's case, it shows you an "uploaded" date: e.g., for one of the public Kubernetes images, https://console.cloud.google.com/gcr/images/google-containers/GLOBAL/k8s-dns-kube-dns-amd64@sha256:40790881bbe9ef4ae4ff7fe8b892498eecb7fe6dcc22661402f271e03f7de344/details/info
(page shows "Uploaded time: June 26, 2017 at 7:44:47 AM UTC+1"). The config referred to in the manifest for that image has the field "created": "2017-06-26T05:45:34.470743089Z" -- close, but not exactly the same date. I suspect for this image it's built in CI, then has some tests before being pushed to gcr.io with the tag. The point is, the date reported by gcr.io is its own, and isn't present in the data available from the registry API.