APIv2: images aren't pulled automatically #6960

gartnera · 2020-07-13T21:44:05Z

Is this a BUG REPORT or FEATURE REQUEST? (leave only one on its own line)

/kind bug

Description

When using APIv2: images aren't pulled automatically for docker run. When running with docker, the image is pulled even if it doesn't exist locally.

Steps to reproduce the issue:

rm -rf /var/lib/containers/
podman system service -t0 --log-level=debug
docker run -it --rm centos

Describe the results you received:

root@podman:~# docker run -it --rm centos
docker: Error response from daemon: NewFromLocal(): unable to find a name and tag match for centos in repotags: no such image.
See 'docker run --help'.

Describe the results you expected:

Should get a shell in a new centos container

Additional information you deem important (e.g. issue happens only occasionally):

Output of podman version:

root@podman:~# podman version
Version:      2.1.0-dev
API Version:  1
Go Version:   go1.13.4
Git Commit:   d86acf2caea68d1dbf349c54d0532b3ce92dcb85-dirty
Built:        Mon Jul 13 21:21:00 2020
OS/Arch:      linux/amd64

Output of podman info --debug:

host:
  arch: amd64
  buildahVersion: 1.16.0-dev
  cgroupVersion: v1
  conmon:
    package: Unknown
    path: /usr/local/libexec/podman/conmon
    version: 'conmon version 2.0.11-dev, commit: 77f4a5131bfc344ab4485cd3f1e4644bfa2122e2'
  cpus: 80
  distribution:
    distribution: ubuntu
    version: "18.04"
  eventLogger: file
  hostname: podman
  idMappings:
    gidmap: null
    uidmap: null
  kernel: 5.3.0-59-generic
  linkmode: dynamic
  memFree: 421032300544
  memTotal: 422679285760
  ociRuntime:
    name: runc
    package: 'runc: /usr/sbin/runc'
    path: /usr/sbin/runc
    version: 'runc version spec: 1.0.1-dev'
  os: linux
  remoteSocket:
    path: /run/podman/podman.sock
  rootless: false
  slirp4netns:
    executable: ""
    package: ""
    version: ""
  swapFree: 0
  swapTotal: 0
  uptime: 413h 3m 27.53s (Approximately 17.21 days)
registries:
  search:
  - docker.io
store:
  configFile: /etc/containers/storage.conf
  containerStore:
    number: 5
    paused: 0
    running: 1
    stopped: 4
  graphDriverName: overlay
  graphOptions: {}
  graphRoot: /var/lib/containers/storage
  graphStatus:
    Backing Filesystem: extfs
    Native Overlay Diff: "false"
    Supports d_type: "true"
    Using metacopy: "false"
  imageStore:
    number: 2
  runRoot: /var/run/containers/storage
  volumePath: /var/lib/containers/storage/volumes
version:
  APIVersion: 1
  Built: 1594675260
  BuiltTime: Mon Jul 13 21:21:00 2020
  GitCommit: d86acf2caea68d1dbf349c54d0532b3ce92dcb85-dirty
  GoVersion: go1.13.4
  OsArch: linux/amd64
  Version: 2.1.0-dev

Output of docker version:

root@podman:~/libpod# docker version
Client:
 Version:           18.09.7
 API version:       1.39
 Go version:        go1.10.1
 Git commit:        2d0083d
 Built:             Fri Aug 16 14:20:06 2019
 OS/Arch:           linux/amd64
 Experimental:      false

Server: linux/amd64/ubuntu-18.04
 Podman Engine:
  Version:          2.1.0-dev
  APIVersion:       1.0.0
  Arch:             amd64
  BuildTime:        2020-07-13T21:21:00Z
  Experimental:     true
  GitCommit:        d86acf2caea68d1dbf349c54d0532b3ce92dcb85-dirty
  GoVersion:        go1.13.4
  KernelVersion:    5.3.0-59-generic
  MinAPIVersion:    1.0.0
  Os:               linux
 Engine:
  Version:          2.1.0-dev
  API version:      1.0.0 (minimum version 1.0.0)
  Go version:       go1.13.4
  Git commit:       d86acf2caea68d1dbf349c54d0532b3ce92dcb85-dirty
  Built:            Mon Jul 13 21:21:00 2020
  OS/Arch:          linux/amd64
  Experimental:     true

root@podman:~/libpod# cat /etc/containers/registries.conf
unqualified-search-registries = ["docker.io"]

Related to: #5386 #6867

The text was updated successfully, but these errors were encountered:

skorhone · 2020-07-14T16:11:54Z

Does docker cli send a create container request to service without explicit pull request?

Iirc podman currently requires explicit pull request when using API. This is one of many issues that will be fixed when code paths between cli and API (for creating containers) are shared.

rhatdan · 2020-07-14T19:00:01Z

This certainly seems like a big issue.
@jwhonce @baude PTAL

gartnera · 2020-07-15T01:15:58Z

Does docker cli send a create container request to service without explicit pull request?

Iirc podman currently requires explicit pull request when using API. This is one of many issues that will be fixed when code paths between cli and API (for creating containers) are shared.

Not unless you specify --pull in the docker run command. Ref: https://github.com/docker/cli/blob/cae16e70b92dcc98ee6f22e064752ba45bd4f645/cli/command/container/run.go#L57

dockerd log snippet for reference:

DEBU[2020-07-14T17:54:50.505958500-07:00] Calling HEAD /_ping                                                                                                                                                     DEBU[2020-07-14T17:54:50.506718400-07:00] Calling POST /v1.40/containers/create                                                                                                                                   DEBU[2020-07-14T17:54:50.506888000-07:00] form data: {"AttachStderr":true,"AttachStdin":true,"AttachStdout":true,"Cmd":null,"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":true,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":[],"CapAdd":null,"CapDrop":null,"Capabilities":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"DeviceRequests":null,"Devices":[],"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"IpcMode":"","Isolation":"","KernelMemory":0,"KernelMemoryTCP":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"MaskedPaths":null,"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyPaths":null,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"centos","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":true,"StdinOnce":true,"Tty":true,"User":"","Volumes":{},"WorkingDir":""}
DEBU[2020-07-14T17:54:50.508544500-07:00] Calling GET /v1.40/info
DEBU[2020-07-14T17:54:50.515330400-07:00] Calling POST /v1.40/images/create?fromImage=centos&tag=latest
DEBU[2020-07-14T17:54:50.515464500-07:00] Trying to pull centos from https://registry-1.docker.io v2
DEBU[2020-07-14T17:54:51.735189400-07:00] Pulling ref from V2 registry: centos:latest
DEBU[2020-07-14T17:54:51.735250500-07:00] docker.io/library/centos:latest resolved to a manifestList object with 3 entries; looking for a unknown/amd64 match                                                     DEBU[2020-07-14T17:54:51.735277400-07:00] found match for linux/amd64 with media type application/vnd.docker.distribution.manifest.v2+json, digest sha256:fd84102fc72960dd1b8da0ee3b4c13e3b0c1d2a085de118bc4c97821cd986e02
DEBU[2020-07-14T17:54:52.176130500-07:00] pulling blob "sha256:6910e5a164f725142d77994b247ba20040477fbab49a721bdbe8d61cf855ac23"                                                                                  DEBU[2020-07-14T17:54:56.701790800-07:00] Downloaded 6910e5a164f7 to tempfile /var/lib/docker/tmp/GetImageBlob969750975                                                                                           DEBU[2020-07-14T17:54:56.710692400-07:00] Applying tar in /var/lib/docker/overlay2/f5be9903d6f7206d83ffb15e523ee98a849081c9020fbda94ab547214720821a/diff  storage-driver=overlay2                                 DEBU[2020-07-14T17:54:58.997076100-07:00] Applied tar sha256:eb29745b8228e1e97c01b1d5c2554a319c00a94d8dd5746a3904222ad65a13f8 to f5be9903d6f7206d83ffb15e523ee98a849081c9020fbda94ab547214720821a, size: 215320025

DEBU[2020-07-14T17:54:59.045721700-07:00] Calling POST /v1.40/containers/create
DEBU[2020-07-14T17:54:59.045901300-07:00] form data: {"AttachStderr":true,"AttachStdin":true,"AttachStdout":true,"Cmd":null,"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":true,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":[],"CapAdd":null,"CapDrop":null,"Capabilities":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[0,0],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"DeviceRequests":null,"Devices":[],"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"IpcMode":"","Isolation":"","KernelMemory":0,"KernelMemoryTCP":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"MaskedPaths":null,"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyPaths":null,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"centos","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":true,"StdinOnce":true,"Tty":true,"User":"","Volumes":{},"WorkingDir":""}
DEBU[2020-07-14T17:54:59.233710100-07:00] container mounted via layerStore: &{/var/lib/docker/overlay2/2df5e39345019f73aac822c01a45330ab130446a527c1ad26cfa4349e1b08c6e/merged 0x55a510d0c000 0x55a510d0c000}     DEBU[2020-07-14T17:54:59.249248200-07:00] Calling POST /v1.40/containers/58e74dc1eebd42f9c3ae685bd27f1c3fed1eac5d41726c2134bb937dade35f0a/attach?stderr=1&stdin=1&stdout=1&stream=1                               DEBU[2020-07-14T17:54:59.249433700-07:00] attach: stdout: begin
DEBU[2020-07-14T17:54:59.249440100-07:00] attach: stdin: begin
DEBU[2020-07-14T17:54:59.249491800-07:00] attach: stderr: begin

skorhone · 2020-07-15T06:49:54Z

Doesn't this mean that result is expected when no --pull is defined?

However, I do suspect that the pull is implemented is incorrect. Docker documentation hints that it supports hijacking connection for creating images (pulling). This is probably required for reporting download status to client. Podman currently doesn't hijack or wait for completion. Thus client can't possibly know when download has completed (with Success or failed).

I suspect that docker hijacks connection and starts publishing progress events when you start pulling.

Because implementing pull requires streaming, I thought that it is unlikely that docker would pull image and create container with just single API call.

mheon · 2020-07-15T13:59:39Z

I don't see any pull parameter in the actual POST /v1.40/containers/create endpoint. And when I try that endpoint with an image that does not exist with Docker, it fails with an "image does not exist" error.

Given all this I'm fairly certain that Docker behaves the same way we do (requires the image be explicitly pulled first).

mheon · 2020-07-15T14:00:23Z

Is the more specific desire here to run docker run against a Podman backend?

gartnera · 2020-07-16T15:49:42Z

Is the more specific desire here to run docker run against a Podman backend?

I'm just running docker against the podman backend to flush out some things I've seen in #5386.

Here's podman system service -t0 --log-level=debug snippet:

DEBU[0425] APIHandler -- Method: GET URL: /_ping
DEBU[0425] IdleTracker 0xc000b1e000:idle 1/47 connection(s)
DEBU[0425] IdleTracker 0xc000b1e000:active 0/47 connection(s)
DEBU[0425] APIHandler -- Method: POST URL: /v1.39/containers/create
DEBU[0425] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]docker.io/library/centos:latest"
DEBU[0425] reference "[overlay@/var/lib/containers/storage+/var/run/containers/storage]docker.io/library/centos:latest" does not resolve to an image ID
DEBU[0425] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]localhost/centos:latest"
DEBU[0425] reference "[overlay@/var/lib/containers/storage+/var/run/containers/storage]localhost/centos:latest" does not resolve to an image ID
INFO[0425] Request Failed(Internal Server Error): NewFromLocal(): unable to find a name and tag match for centos in repotags: no such image
DEBU[0425] IdleTracker 0xc000b1e000:idle 1/48 connection(s)
DEBU[0425] IdleTracker 0xc000b1e000:closed 0/48 connection(s)

With the dockerd backend (see log above), the /v1.40/images/create?fromImage=centos&tag=latest is explicitly called. But for some reason with the podman backend it isn't.

Ok looking at the createContainer function herhttps://github.com/docker/cli/blob/cae16e70b92dcc98ee6f22e064752ba45bd4f645/cli/command/container/create.go#L261, it looks like the backend should be returning 404 when the container image doesn't exist. But it looks like podman is returning 500.

same logic in docker-py

mheon · 2020-07-16T15:52:21Z

Ahhh. That would explain it, and should be a pretty easy fix.

This matches Docker behavior, and will make the Docker frontend work with `podman system service` (Docker tries to create, then if that fails with 404 sends a request to pull the image). Fixes containers#6960 Signed-off-by: Matthew Heon <[email protected]>

mheon · 2020-07-16T18:21:53Z

#7003 to fix

gartnera · 2020-07-17T16:20:44Z

Somewhere No such image gets lowercased to no such image in the error string. docker-py requires the string to contain exactly No such image.

DEBU[0315] IdleTracker 0xc0002dc1d0:new 0/38 connection(s)
DEBU[0315] IdleTracker 0xc0002dc1d0:active 1/39 connection(s)
DEBU[0315] APIHandler -- Method: GET URL: /_ping
DEBU[0315] IdleTracker 0xc0002dc1d0:idle 1/40 connection(s)
DEBU[0315] IdleTracker 0xc0002dc1d0:active 0/40 connection(s)
DEBU[0315] APIHandler -- Method: DELETE URL: /v1.39/images/centos
DEBU[0315] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]docker.io/library/centos:latest"
DEBU[0315] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]@831691599b88ad6cc2a4abbd0e89661a121aff14cfa289ad840fd3946f274f1f"
DEBU[0315] exporting opaque data as blob "sha256:831691599b88ad6cc2a4abbd0e89661a121aff14cfa289ad840fd3946f274f1f"
DEBU[0315] IdleTracker 0xc0002dc1d0:idle 1/41 connection(s)
DEBU[0315] IdleTracker 0xc0002dc1d0:closed 0/41 connection(s)
DEBU[0322] IdleTracker 0xc0005da110:new 0/41 connection(s)
DEBU[0322] IdleTracker 0xc0005da110:active 1/42 connection(s)
DEBU[0322] APIHandler -- Method: POST URL: /v1.35/containers/create
DEBU[0322] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]docker.io/library/centos:latest"
DEBU[0322] reference "[overlay@/var/lib/containers/storage+/var/run/containers/storage]docker.io/library/centos:latest" does not resolve to an image ID
DEBU[0322] parsed reference into "[overlay@/var/lib/containers/storage+/var/run/containers/storage]localhost/centos:latest"
DEBU[0322] reference "[overlay@/var/lib/containers/storage+/var/run/containers/storage]localhost/centos:latest" does not resolve to an image ID
INFO[0322] Request Failed(Not Found): unable to find a name and tag match for centos in repotags: no such image
DEBU[0322] IdleTracker 0xc0005da110:idle 1/43 connection(s)

Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/root/docker-py/docker/models/containers.py", line 803, in run
    detach=detach, **kwargs)
  File "/root/docker-py/docker/models/containers.py", line 861, in create
    resp = self.client.api.create_container(**create_kwargs)
  File "/root/docker-py/docker/api/container.py", line 430, in create_container
    return self.create_container_from_config(config, name)
  File "/root/docker-py/docker/api/container.py", line 441, in create_container_from_config
    return self._result(res, True)
  File "/root/docker-py/docker/api/client.py", line 267, in _result
    self._raise_for_status(response)
  File "/root/docker-py/docker/api/client.py", line 263, in _raise_for_status
    raise create_api_error_from_http_exception(e)
  File "/root/docker-py/docker/errors.py", line 31, in create_api_error_from_http_exception
    raise cls(e, response=response, explanation=explanation)
docker.errors.NotFound: 404 Client Error: Not Found ("unable to find a name and tag match for centos in repotags: no such image")

rhatdan · 2020-07-20T13:37:12Z

All podman error codes start with lower case.

ErrNoSuchImage = errors.New("no such image")

mheon · 2020-07-20T13:46:21Z

I think we basically need to intercept those calls, and re-wrap with a new, capitalized error? It's very gross (we either have to duplicate the ErrNoSuchImage bit at the end, with a second capitalized version, or risk losing the error chain and the c/image bits that explain what actually went wrong)

openshift-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Jul 13, 2020

mheon mentioned this issue Jul 16, 2020

The compat create endpoint should 404 on no such image #7003

Merged

openshift-merge-robot closed this as completed in #7003 Jul 16, 2020

github-actions bot added the locked - please file new issue/PR Assist humans wanting to comment on an old issue or PR with locked comments. label Sep 23, 2023

github-actions bot locked as resolved and limited conversation to collaborators Sep 23, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

APIv2: images aren't pulled automatically #6960

APIv2: images aren't pulled automatically #6960

gartnera commented Jul 13, 2020

skorhone commented Jul 14, 2020

rhatdan commented Jul 14, 2020

gartnera commented Jul 15, 2020

skorhone commented Jul 15, 2020

mheon commented Jul 15, 2020

mheon commented Jul 15, 2020

gartnera commented Jul 16, 2020 •

edited

Loading

mheon commented Jul 16, 2020

mheon commented Jul 16, 2020

gartnera commented Jul 17, 2020

rhatdan commented Jul 20, 2020

mheon commented Jul 20, 2020

APIv2: images aren't pulled automatically #6960

APIv2: images aren't pulled automatically #6960

Comments

gartnera commented Jul 13, 2020

skorhone commented Jul 14, 2020

rhatdan commented Jul 14, 2020

gartnera commented Jul 15, 2020

skorhone commented Jul 15, 2020

mheon commented Jul 15, 2020

mheon commented Jul 15, 2020

gartnera commented Jul 16, 2020 • edited Loading

mheon commented Jul 16, 2020

mheon commented Jul 16, 2020

gartnera commented Jul 17, 2020

rhatdan commented Jul 20, 2020

mheon commented Jul 20, 2020

gartnera commented Jul 16, 2020 •

edited

Loading