Skip to content

Insufficient debug logging when fetching multi-arch images #22106

New issue
New issue
Closed
Closed
Insufficient debug logging when fetching multi-arch images#22106
Labels
area/distributionImage Distributionkind/enhancementEnhancements are not bugs or new features but can improve usability or performance.version/master
@friism

Description

@friism
friism
opened on Apr 17, 2016

Output of docker version:

Client:
 Version:      1.11.0-dev
 API version:  1.24
 Go version:   go1.5.3
 Git commit:   577adcc
 Built:        Mon Apr 11 17:20:50 2016
 OS/Arch:      windows/amd64

Server:
 Version:      1.11.0-dev
 API version:  1.24
 Go version:   go1.5.3
 Git commit:   577adcc
 Built:        Mon Apr 11 17:20:50 2016
 OS/Arch:      windows/amd64

Output of docker info:

Containers: 31
 Running: 0
 Paused: 0
 Stopped: 31
Images: 54
Server Version: 1.11.0-dev
Storage Driver: windowsfilter
 Windows:
Logging Driver: json-file
Plugins:
 Volume: local
 Network: nat null
Kernel Version: 10.0 14316 (14316.1000.amd64fre.rs1_release.160402-2217)
Operating System: Windows Server 2016 Datacenter Technical Preview 5
OSType: windows
Architecture: x86_64
CPUs: 4
Total Memory: 1.186 GiB
Name: WIN-8F5EG07ROBB
ID: VKYM:E5F7:CMIT:4ZMS:OGUG:W43U:API4:ATWI:3S5X:RO54:DU4Q:YOFD
Docker Root Dir: C:\ProgramData\docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: -1
 Goroutines: 37
 System Time: 2016-04-17T11:48:29.5712882-07:00
 EventsListeners: 0
Registry: https://index.docker.io/v1/
Insecure registries:
 127.0.0.0/8

Steps to reproduce the issue:

  1. create and push multi-arch image / manifest list (see https://github.com/estesp/manifest-tool)
  2. pull said image from daemon and look at daemon logs

Describe the results you received:

time="2016-04-17T11:45:50.554583300-07:00" level=info msg="API listen on [::]:2376"
time="2016-04-17T11:46:01.005158900-07:00" level=debug msg="Calling POST /v1.23/images/create?fromImage=registry-1-stage.docker.io%2Ffriism%2Fgolang%3Amulti"
time="2016-04-17T11:46:22.258586500-07:00" level=debug msg="hostDir: C:\\ProgramData\\docker\\certs.d\\registry-1-stage.docker.io"
time="2016-04-17T11:46:22.263581400-07:00" level=debug msg="hostDir: C:\\ProgramData\\docker\\certs.d\\registry-1-stage.docker.io"
time="2016-04-17T11:46:22.274581200-07:00" level=debug msg="Trying to pull registry-1-stage.docker.io/friism/golang from https://registry-1-stage.docker.io v2"
time="2016-04-17T11:46:23.645928700-07:00" level=debug msg="Increasing token expiration to: 60 seconds"
time="2016-04-17T11:46:24.229417500-07:00" level=debug msg="Pulling ref from V2 registry: registry-1-stage.docker.io/friism/golang:multi"
time="2016-04-17T11:46:26.360726700-07:00" level=debug msg="pulling blob \"sha256:7470d436363f11408f0c469a44d8b0758bba3908abdb97441e2934b7896fcfed\""
time="2016-04-17T11:46:26.364727400-07:00" level=debug msg="pulling blob \"sha256:5b35e7d42407de446863a13c71a36f565165bd511e5eee283dac83aa19bdbdb3\""
time="2016-04-17T11:46:26.364727400-07:00" level=debug msg="pulling blob \"sha256:fa35b1c0641e918397dde5f66d1077e7582bbd47f989da6aef8d6c1b5f0ad98d\""
time="2016-04-17T11:46:27.479404800-07:00" level=debug msg="Downloaded 5b35e7d42407 to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\GetImageBlob299139312"
time="2016-04-17T11:46:27.516593100-07:00" level=debug msg="pulling blob \"sha256:d763d2edb89a5873905624791a129979e6e7f123377e08b1d188b507247069a3\""
time="2016-04-17T11:46:27.639580700-07:00" level=debug msg="Downloaded 7470d436363f to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\GetImageBlob465392789"
time="2016-04-17T11:46:27.675594700-07:00" level=debug msg="hcsshim::GetLayerMountPath Flavour 1 ID CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:27.678589200-07:00" level=debug msg="Calling proc (1)"
time="2016-04-17T11:46:27.682566000-07:00" level=debug msg="Calling proc (2)"
time="2016-04-17T11:46:27.684564100-07:00" level=debug msg="hcsshim::GetLayerMountPath succeeded flavour=1 id=CN=Microsoft_WindowsServerCore_10.0.14316.1000 path=C:\\ProgramData\\Microsoft\\Windows\\Images\\CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:27.688586100-07:00" level=debug msg="hcsshim::CreateLayer Flavour 1 ID e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe parent CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:27.702589700-07:00" level=debug msg="hcsshim::CreateLayer  - succeeded id=e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe parent=CN=Microsoft_WindowsServerCore_10.0.14316.1000 flavour=1"
time="2016-04-17T11:46:27.708568800-07:00" level=debug msg="hcsshim::GetLayerMountPath Flavour 1 ID CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:27.711587900-07:00" level=debug msg="Calling proc (1)"
time="2016-04-17T11:46:27.717561900-07:00" level=debug msg="Calling proc (2)"
time="2016-04-17T11:46:27.719567300-07:00" level=debug msg="hcsshim::GetLayerMountPath succeeded flavour=1 id=CN=Microsoft_WindowsServerCore_10.0.14316.1000 path=C:\\ProgramData\\Microsoft\\Windows\\Images\\CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:27.735564600-07:00" level=debug msg="hcsshim::ImportLayer flavour 1 layerId \\\\?\\C:\\ProgramData\\docker\\windowsfilter\\e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe folder C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\hcs700486948"
time="2016-04-17T11:46:27.736565100-07:00" level=debug msg="hcsshim::NameToGuid Name CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:28.547457300-07:00" level=debug msg="hcsshim::ImportLayer succeeded flavour=1 layerId=\\\\?\\C:\\ProgramData\\docker\\windowsfilter\\e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe folder=C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\hcs700486948"
time="2016-04-17T11:46:28.554394700-07:00" level=debug msg="Applied tar sha256:ef36ac736aefb69ca9d70837e69d8a247858496488b73d8bd0704e2b48e3d977 to e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe, size: 40960"
time="2016-04-17T11:46:28.566373500-07:00" level=debug msg="hcsshim::GetLayerMountPath Flavour 1 ID e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.567374300-07:00" level=debug msg="Calling proc (1)"
time="2016-04-17T11:46:28.568371000-07:00" level=debug msg="Calling proc (2)"
time="2016-04-17T11:46:28.576372600-07:00" level=debug msg="hcsshim::GetLayerMountPath succeeded flavour=1 id=e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe path=C:\\ProgramData\\docker\\windowsfilter\\e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.583371200-07:00" level=debug msg="hcsshim::CreateLayer Flavour 1 ID 41806b8b2a5d544e71677ca34dcd26d1645210f372ab261f15aa35cb19fd2ea8 parent e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.585370800-07:00" level=debug msg="hcsshim::CreateLayer  - succeeded id=41806b8b2a5d544e71677ca34dcd26d1645210f372ab261f15aa35cb19fd2ea8 parent=e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe flavour=1"
time="2016-04-17T11:46:28.598374000-07:00" level=debug msg="hcsshim::GetLayerMountPath Flavour 1 ID e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.610627000-07:00" level=debug msg="Calling proc (1)"
time="2016-04-17T11:46:28.616390500-07:00" level=debug msg="Calling proc (2)"
time="2016-04-17T11:46:28.621418200-07:00" level=debug msg="hcsshim::GetLayerMountPath succeeded flavour=1 id=e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe path=C:\\ProgramData\\docker\\windowsfilter\\e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.642375100-07:00" level=debug msg="hcsshim::ImportLayer flavour 1 layerId \\\\?\\C:\\ProgramData\\docker\\windowsfilter\\41806b8b2a5d544e71677ca34dcd26d1645210f372ab261f15aa35cb19fd2ea8 folder C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\hcs014645238"
time="2016-04-17T11:46:28.643375500-07:00" level=debug msg="hcsshim::NameToGuid Name e901ed228bbdd506641236334c2fb9dcb30ec32c4ede1bd7f2453e6c1bea2ebe"
time="2016-04-17T11:46:28.648448200-07:00" level=debug msg="hcsshim::NameToGuid Name CN=Microsoft_WindowsServerCore_10.0.14316.1000"
time="2016-04-17T11:46:29.788441700-07:00" level=debug msg="hcsshim::ImportLayer succeeded flavour=1 layerId=\\\\?\\C:\\ProgramData\\docker\\windowsfilter\\41806b8b2a5d544e71677ca34dcd26d1645210f372ab261f15aa35cb19fd2ea8 folder=C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\hcs014645238"
time="2016-04-17T11:46:29.795448200-07:00" level=debug msg="Applied tar sha256:f80131f040eb322cad65669adf69ee07df0c8ac4a17710700d5c346836838270 to 41806b8b2a5d544e71677ca34dcd26d1645210f372ab261f15aa35cb19fd2ea8, size: 40960"
time="2016-04-17T11:46:34.200914500-07:00" level=debug msg="Downloaded d763d2edb89a to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\1\\GetImageBlob898630050"

Describe the results you expected:

Something about a manifest list being received and info on how the manifest to download was chosen.

cc @dmp42

Metadata

Metadata

Assignees

No one assigned

    Labels

    area/distributionImage Distributionkind/enhancementEnhancements are not bugs or new features but can improve usability or performance.version/master

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions