Skip to content

Console Output

+ E2E_UNIQUE_ID=clie2e1 IMAGE_TAG=clie2e1 DOCKER_BUILDKIT=1 make -f docker.Makefile test-e2e-experimental
docker build -t docker-cli-e2eclie2e1 --build-arg=GO_VERSION --build-arg VERSION=20.03.0-dev --build-arg GITCOMMIT= -f ./dockerfiles/Dockerfile.e2e .
#2 [internal] load build definition from Dockerfile.e2e
#2 transferring dockerfile: 42B done
#2 DONE 0.0s

#1 [internal] load .dockerignore
#1 transferring context: 34B done
#1 DONE 0.0s

#3 [internal] load metadata for docker.io/library/golang:1.13.15-buster
#3 DONE 0.2s

#4 [1/11] FROM docker.io/library/golang:1.13.15-buster@sha256:66a3f6817c129...
#4 DONE 0.0s

#10 [internal] load build context
#10 transferring context: 393.89kB 0.2s done
#10 DONE 0.2s

#11 [7/11] COPY e2e/testdata/notary/root-ca.cert /usr/share/ca-certificates/...
#11 CACHED

#14 [10/11] RUN ./scripts/build/binary
#14 CACHED

#5 [2/11] RUN apt-get update && apt-get install -y     build-essential     ...
#5 CACHED

#7 [4/11] RUN curl -fsSL https://github.com/theupdateframework/notary/relea...
#7 CACHED

#9 [6/11] WORKDIR /go/src/github.com/docker/cli
#9 CACHED

#13 [9/11] COPY . .
#13 CACHED

#6 [3/11] RUN curl -fsSL https://github.com/docker/compose/releases/downloa...
#6 CACHED

#8 [5/11] RUN curl -fsSL https://github.com/gotestyourself/gotestsum/releas...
#8 CACHED

#12 [8/11] RUN echo 'notary.cert' >> /etc/ca-certificates.conf && update-ca-...
#12 CACHED

#15 [11/11] RUN ./scripts/build/plugins e2e/cli-plugins/plugins/*
#15 CACHED

#16 exporting to image
#16 exporting layers done
#16 writing image sha256:11bf6470a145dfd94f65989866ad405d1584301d5dda3d41e7e2583be0188e35
#16 writing image sha256:11bf6470a145dfd94f65989866ad405d1584301d5dda3d41e7e2583be0188e35 done
#16 naming to docker.io/library/docker-cli-e2eclie2e1 done
#16 DONE 0.0s
docker run --rm --mount type=bind,src=/var/run/docker.sock,dst=/var/run/docker.sock -e VERSION=20.03.0-dev -e GITCOMMIT -e PLATFORM -e TESTFLAGS -e TESTDIRS -e GOOS -e GOARCH -e GOARM -e TEST_ENGINE_VERSION= -e DOCKERD_EXPERIMENTAL=1 docker-cli-e2eclie2e1
Native build is an experimental feature and could change at any time
Creating network "cliendtoendsuite_default" with the default driver
Building evil-notary-server
#2 [internal] load .dockerignore
#2 sha256:046bf340f49ccbb803e3d72843d3bdba0b89bc8f4ad613d25b72033d64abbc9a
#2 transferring context: 2B done
#2 DONE 0.0s

#1 [internal] load build definition from Dockerfile.evil-notary-server
#1 sha256:c7e40db9b005874550252640d1679a1507b724a248cdffd9e9fa3102a0888f1c
#1 transferring dockerfile: 150B done
#1 DONE 0.0s

#3 [internal] load metadata for docker.io/library/notary:server-0.5.0
#3 sha256:a1da53cf05b63d7b254e8b6a3d96b994c4ae5f01cb10e10906db53f729e6903e
#3 DONE 0.1s

#4 [1/2] FROM docker.io/library/notary:server-0.5.0@sha256:d59e4ecc20198447a9818e7f16d0a02ba1d9905de71e5354bc8ee0017304a244
#4 sha256:cd52ec412b0b1cb53bf96e4160cee4046ce1447da482224a0d115d68a2468239
#4 DONE 0.0s

#5 [internal] load build context
#5 sha256:831c9835e1bf01a59645dea8441585935efa65247d8c3a2cd5796c63e4be7c0d
#5 transferring context: 5.73kB done
#5 DONE 0.0s

#6 [2/2] COPY ./notary-evil/ /fixtures/
#6 sha256:e91fbfb58ddf985cd0328446f7374ca8ad461aa0952d178b0e18d3a2e442e8cf
#6 CACHED

#7 exporting to image
#7 sha256:e8c613e07b0b7ff33893b694f7759a10d42e180f2b4dc349fb57dc6b71dcab00
#7 exporting layers done
#7 writing image sha256:076be5ceee8a42397c1f151c32d4e7f923a3c2c61797b797376266ccb80ff51b done
#7 naming to docker.io/library/cliendtoendsuite_evil-notary-server done
#7 DONE 0.0s
Successfully built 076be5ceee8a42397c1f151c32d4e7f923a3c2c61797b797376266ccb80ff51b
Building notary-server
#2 [internal] load .dockerignore
#2 sha256:3833d23665a2773b18378ca0cd357c2137633c818ea2c3c6c90051e69fc43785
#2 DONE 0.0s

#1 [internal] load build definition from Dockerfile.notary-server
#1 sha256:91edfb38b9e2aa1e4dcdfe13fdb63c621770c4d2cb6cc9a6328ae641426feb19
#1 transferring dockerfile: 140B done
#1 DONE 0.0s

#2 [internal] load .dockerignore
#2 sha256:3833d23665a2773b18378ca0cd357c2137633c818ea2c3c6c90051e69fc43785
#2 transferring context: 2B done
#2 DONE 0.0s

#3 [internal] load metadata for docker.io/library/notary:server-0.5.0
#3 sha256:a1da53cf05b63d7b254e8b6a3d96b994c4ae5f01cb10e10906db53f729e6903e
#3 DONE 0.2s

#4 [1/2] FROM docker.io/library/notary:server-0.5.0@sha256:d59e4ecc20198447a9818e7f16d0a02ba1d9905de71e5354bc8ee0017304a244
#4 sha256:cd52ec412b0b1cb53bf96e4160cee4046ce1447da482224a0d115d68a2468239
#4 DONE 0.0s

#5 [internal] load build context
#5 sha256:0bc3a8e1faf24e74e03d0831eabe6d631f19eebeb5b3d8ba30ad171787c82f0e
#5 transferring context: 5.70kB done
#5 DONE 0.0s

#6 [2/2] COPY ./notary/ /fixtures/
#6 sha256:b558b762ff25356fe39dd32b96a8e0219afa6887f66fb111fc930967864f4961
#6 CACHED

#7 exporting to image
#7 sha256:e8c613e07b0b7ff33893b694f7759a10d42e180f2b4dc349fb57dc6b71dcab00
#7 exporting layers done
#7 writing image sha256:79a84b7cfc8503e4a8452ee7f9db922aff9bf4eb1fb970487afd5986dd5b022d done
#7 naming to docker.io/library/cliendtoendsuite_notary-server done
#7 DONE 0.0s
Successfully built 79a84b7cfc8503e4a8452ee7f9db922aff9bf4eb1fb970487afd5986dd5b022d
Creating cliendtoendsuite_evil-notary-server_1 ... 
Creating cliendtoendsuite_notary-server_1      ... 
Creating cliendtoendsuite_engine_1             ... 
Creating cliendtoendsuite_registry_1           ... 

Creating cliendtoendsuite_registry_1           ... done

Creating cliendtoendsuite_notary-server_1      ... done

Creating cliendtoendsuite_evil-notary-server_1 ... done

Creating cliendtoendsuite_engine_1             ... done
Waiting for docker daemon to become available at tcp://172.20.0.4:2375
Client:
 Version:           20.03.0-dev
 API version:       1.40
 Go version:        go1.13.15
 Git commit:        
 Built:             Fri Sep 18 00:06:06 2020
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      false

Server: Docker Engine - Community
 Engine:
  Version:          19.03.13
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       4484c46
  Built:            Wed Sep 16 17:04:43 2020
  OS/Arch:          linux/amd64
  Experimental:     true
 containerd:
  Version:          v1.3.7
  GitCommit:        8fba4e9a7d01810a393d5d25a3621dc101981175
 runc:
  Version:          1.0.0-rc10
  GitCommit:        dc9208a3303feef5b3839f4323d9beb36df0a9dd
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683
sha256:f006ecbb824d87947d0b51ab8488634bf69fe4094959d935c0c103f4820a417d: Pulling from library/alpine
88286f41530e: Pulling fs layer
88286f41530e: Download complete
88286f41530e: Pull complete
Digest: sha256:f006ecbb824d87947d0b51ab8488634bf69fe4094959d935c0c103f4820a417d
Status: Downloaded newer image for alpine@sha256:f006ecbb824d87947d0b51ab8488634bf69fe4094959d935c0c103f4820a417d
docker.io/library/alpine@sha256:f006ecbb824d87947d0b51ab8488634bf69fe4094959d935c0c103f4820a417d
The push refers to repository [registry:5000/alpine]
5bef08742407: Preparing
5bef08742407: Pushed
3.6: digest: sha256:641b95ddb2ea9dc2af1a0113b6b348ebc20872ba615204fbe12148e98fd6f23d size: 528
sha256:3e8fa85ddfef1af9ca85a5cfb714148956984e02f00bec3f7f49d3925a91e0e7: Pulling from library/busybox
03b1be98f3f9: Pulling fs layer
03b1be98f3f9: Verifying Checksum
03b1be98f3f9: Download complete
03b1be98f3f9: Pull complete
Digest: sha256:3e8fa85ddfef1af9ca85a5cfb714148956984e02f00bec3f7f49d3925a91e0e7
Status: Downloaded newer image for busybox@sha256:3e8fa85ddfef1af9ca85a5cfb714148956984e02f00bec3f7f49d3925a91e0e7
docker.io/library/busybox@sha256:3e8fa85ddfef1af9ca85a5cfb714148956984e02f00bec3f7f49d3925a91e0e7
The push refers to repository [registry:5000/busybox]
6a749002dd6a: Preparing
6a749002dd6a: Pushed
1.27.2: digest: sha256:030fcb92e1487b18c974784dcc110a93147c9fc402188370fbfd17efabffc6af size: 527
Swarm initialized: current node (wvkmnv2knyudti06jkuyithma) is now a manager.

To add a worker to this swarm, run the following command:

    docker swarm join --token SWMTKN-1-2bjhmqf9maxvrm1jxsv6ey26cgozyymxu7ud4j7ia33dgddew7-aujrej39r91p5euqgnlhp6go1 172.20.0.4:2377

To add a manager to this swarm, run 'docker swarm join-token manager' and follow the instructions.

✓  e2e/cli-plugins (2.797s)
∅  e2e/cli-plugins/plugins/badmeta
∅  e2e/cli-plugins/plugins/nopersistentprerun
✓  e2e/context (45ms)
✓  e2e/global (114ms)
✓  e2e/container (9.004s)
✓  e2e/plugin (3.621s)
✓  e2e/stack (666ms)
✓  e2e/system (76ms)
✓  e2e/image (13.792s)
∅  e2e/internal/fixtures
∅  e2e/plugin/basic
✖  e2e/trust (2.48s)

=== Skipped
=== SKIP: e2e/cli-plugins TestCLIPluginDialStdio (0.00s)
    dial_test.go:16: skipping plugin dial-stdio test since DOCKER_CLI_PLUGIN_USE_DIAL_STDIO is not set

=== SKIP: e2e/container TestRunWithCgroupNamespace (0.09s)
    run_test.go:141: !cgroupNsFound: running against a daemon that doesn't support cgroup namespaces (security options: [name=apparmor name=seccomp,profile=default]
        )

=== SKIP: e2e/stack TestDeployWithNamedResources/Kubernetes (0.00s)
    --- SKIP: TestDeployWithNamedResources/Kubernetes (0.00s)
        deploy_test.go:22: FIXME(chris-crone): currently does not work with compose for kubernetes.

=== SKIP: e2e/stack TestRemove/Kubernetes (0.00s)
    --- SKIP: TestRemove/Kubernetes (0.00s)
        remove_test.go:22: !environment.KubernetesEnabled()


=== Failed
=== FAIL: e2e/trust TestSignWithLocalFlag (0.31s)
    sign_test.go:57: assertion failed: 
        Command:  docker -D trust sign registry:5000/signlocal:v1
        ExitCode: 1
        Error:    exit status 1
        Stdout:   Created signer: eiais
        Finished initializing signed repository for registry:5000/signlocal:v1
        The push refers to repository [registry:5000/signlocal]
        5bef08742407: Preparing
        5bef08742407: Mounted from sign
        v1: digest: sha256:641b95ddb2ea9dc2af1a0113b6b348ebc20872ba615204fbe12148e98fd6f23d size: 528
        Signing and pushing trust metadata
        
        Stderr:   time="2020-09-18T00:09:42Z" level=debug msg="reading certificate directory: /tmp/trust_test-641298897/tls/notary-server:4443"
        time="2020-09-18T00:09:42Z" level=debug msg="Making dir path: /tmp/trust_test-641298897/trust/tuf/registry:5000/signlocal/changelist"
        time="2020-09-18T00:09:42Z" level=debug msg="received HTTP status 404 when requesting root."
        time="2020-09-18T00:09:42Z" level=debug msg="generated ECDSA key with keyID: d19930816a220b54a7dfdd2c4af5aa055d2d426891fe4eebd7d5077294972311"
        time="2020-09-18T00:09:42Z" level=debug msg="generated new ecdsa key for role: root and keyID: d19930816a220b54a7dfdd2c4af5aa055d2d426891fe4eebd7d5077294972311"
        time="2020-09-18T00:09:42Z" level=debug msg="generated ECDSA key with keyID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="generated new ecdsa key for role: targets and keyID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="got remote timestamp ed25519 key with keyID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="got remote snapshot ed25519 key with keyID: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="generating new snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="Saving changes to Trusted Collection."
        time="2020-09-18T00:09:42Z" level=debug msg="signing root..."
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 0/0 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign targets called for role targets"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 0/0 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="generated ECDSA key with keyID: 79236fc4c0188b544a8f762d2a2f1602e09ccc76c6e34979c1b21dc4fe4d933e"
        time="2020-09-18T00:09:42Z" level=debug msg="generated new ecdsa key for role: eiais and keyID: 79236fc4c0188b544a8f762d2a2f1602e09ccc76c6e34979c1b21dc4fe4d933e"
        time="2020-09-18T00:09:42Z" level=debug msg="Adding delegation \"targets/eiais\" with threshold 1, and 1 keys\\n"
        time="2020-09-18T00:09:42Z" level=debug msg="Adding [] paths to delegation targets/eiais\\n"
        time="2020-09-18T00:09:42Z" level=debug msg="Adding delegation \"targets/releases\" with threshold 1, and 1 keys\\n"
        time="2020-09-18T00:09:42Z" level=debug msg="Adding [] paths to delegation targets/releases\\n"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="received HTTP status 404 when requesting root."
        time="2020-09-18T00:09:42Z" level=debug msg="Loading trusted collection."
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="role targets/eiais with no Paths will never be able to publish content until one or more are added"
        time="2020-09-18T00:09:42Z" level=debug msg="role targets/releases with no Paths will never be able to publish content until one or more are added"
        time="2020-09-18T00:09:42Z" level=debug msg="applied 4 change(s)"
        time="2020-09-18T00:09:42Z" level=debug msg="sign targets called for role targets"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 0/0 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="generating new snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="signing snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="Client does not have the key to sign snapshot. Assuming that server should sign the snapshot."
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="updating TUF client"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading timestamp..."
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="no snapshot in cache, must download"
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for snapshot.636f88dfd6f365fb8160800c066b23461ce320fd6334f1f574972a47ad428e16"
        time="2020-09-18T00:09:42Z" level=debug msg="snapshot role has key IDs: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded snapshot.636f88dfd6f365fb8160800c066b23461ce320fd6334f1f574972a47ad428e16"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading targets..."
        time="2020-09-18T00:09:42Z" level=debug msg="cached targets is invalid (must download): sha256 checksum for targets did not match: expected 4da8e3170f117dc6ea1512d8e73470b9c86ccd6c191f130393174f08889e2bcd"
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for targets.4da8e3170f117dc6ea1512d8e73470b9c86ccd6c191f130393174f08889e2bcd"
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded targets.4da8e3170f117dc6ea1512d8e73470b9c86ccd6c191f130393174f08889e2bcd"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/eiais because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/releases because there is no checksum for it"
        Signing and pushing trust data for local image registry:5000/signlocal:v1, may overwrite remote trust data
        time="2020-09-18T00:09:42Z" level=debug msg="reading certificate directory: /tmp/trust_test-641298897/tls/notary-server:4443"
        time="2020-09-18T00:09:42Z" level=debug msg="Making dir path: /tmp/trust_test-641298897/trust/tuf/registry:5000/signlocal/changelist"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="updating TUF client"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading timestamp..."
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="snapshot role has key IDs: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached snapshot"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading targets..."
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached targets"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/eiais because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/releases because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="updating TUF client"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading timestamp..."
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="snapshot role has key IDs: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached snapshot"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading targets..."
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached targets"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/eiais because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/releases because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="Adding target \"v1\" with sha256 \"641b95ddb2ea9dc2af1a0113b6b348ebc20872ba615204fbe12148e98fd6f23d\" and size 528 bytes.\n"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="entered ValidateRoot with dns: registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="found the following root keys: [a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3]"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 valid leaf certificates for registry:5000/signlocal: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="found 1 leaf certs, of which 1 are valid leaf certs for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking root against trust_pinning config for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="checking trust-pinning for cert: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg=" role has key IDs: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: a916ff31453620eb225cfab3ff176e7ebb28260b04645a645a3a54221b06d1e3"
        time="2020-09-18T00:09:42Z" level=debug msg="root validation succeeded for registry:5000/signlocal"
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for root"
        time="2020-09-18T00:09:42Z" level=debug msg="updating TUF client"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading timestamp..."
        time="2020-09-18T00:09:42Z" level=debug msg="200 when retrieving metadata for timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="timestamp role has key IDs: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: bf70baeb00b7479612e8d24876e182575a3ca8036d1e961459f81829f6046abd"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified downloaded timestamp"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="snapshot role has key IDs: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 8e5617bfe8203393f5860c254418d53ff5d06f59e05feab65b54d0d120a7e610"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached snapshot"
        time="2020-09-18T00:09:42Z" level=debug msg="Loading targets..."
        time="2020-09-18T00:09:42Z" level=debug msg="targets role has key IDs: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="verifying signature for key ID: 202fb69a7b717c7ebd5f7d561cc6f552cd1d939b3c66acbdf5a25c4435ea44ab"
        time="2020-09-18T00:09:42Z" level=debug msg="successfully verified cached targets"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/eiais because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="skipping targets/releases because there is no checksum for it"
        time="2020-09-18T00:09:42Z" level=debug msg="changelist add: v1"
        time="2020-09-18T00:09:42Z" level=debug msg="changelist add: v1"
        time="2020-09-18T00:09:42Z" level=debug msg="applied 2 change(s)"
        time="2020-09-18T00:09:42Z" level=debug msg="sign targets called for role targets/eiais"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 0/0 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign targets called for role targets/releases"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 0/0 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="signing snapshot..."
        time="2020-09-18T00:09:42Z" level=debug msg="sign called with 1/1 required keys"
        time="2020-09-18T00:09:42Z" level=debug msg="Client does not have the key to sign snapshot. Assuming that server should sign the snapshot."
        failed to sign registry:5000/signlocal:v1: remote error: tls: bad record MAC
        
        
        Failures:
        ExitCode was 1 expected 0
        Expected no error


DONE 94 tests, 4 skipped, 1 failure in 33.880s
Stopping cliendtoendsuite_engine_1             ... 
Stopping cliendtoendsuite_registry_1           ... 
Stopping cliendtoendsuite_evil-notary-server_1 ... 
Stopping cliendtoendsuite_notary-server_1      ... 

Stopping cliendtoendsuite_notary-server_1      ... done

Stopping cliendtoendsuite_evil-notary-server_1 ... done

Stopping cliendtoendsuite_registry_1           ... done

Stopping cliendtoendsuite_engine_1             ... done
Removing cliendtoendsuite_engine_1             ... 
Removing cliendtoendsuite_registry_1           ... 
Removing cliendtoendsuite_evil-notary-server_1 ... 
Removing cliendtoendsuite_notary-server_1      ... 

Removing cliendtoendsuite_notary-server_1      ... done

Removing cliendtoendsuite_evil-notary-server_1 ... done

Removing cliendtoendsuite_engine_1             ... done

Removing cliendtoendsuite_registry_1           ... done
Removing network cliendtoendsuite_default
Removing image cliendtoendsuite_notary-server
Removing image cliendtoendsuite_evil-notary-server
docker.Makefile:148: recipe for target 'test-e2e-experimental' failed
make: *** [test-e2e-experimental] Error 1