This is similar to this other thread but the pull works when on the system drive, e.g. C:\, it only receives this error when graph/data-root is on a non-system drive, e.g. D:.
Troubleshooting steps I have tried so far:
- Uninstall all other software
- Disabled/Uninstalled Windows Defender
- Remove/Add Containers feature
- Tried Docker 17.03 to 17.06.1-ee-2
- MSConfig with the Diagnostics Startup
- Verified Administrators have SeBackupPrivilege
- Enabled in-process
SET DOCKER_WINDOWSFILTER_NOREEXEC=1 - Tried elevating privleges of the process with: www.leeholmes.com/blog/2010/09/24/adjusting-token-privileges-in-powershell/
- Verified FLTMC shows no unexpected drivers/instances on the D drive
- Tried both the graph and data-root path with same result
- PROCMON does not show any access denied messages
- Tried using a locally attached VHDX drive
I've tracked down this error to originate around winio.OpenForBackup which calls syscall.CreateFile with the syscall.FILE_FLAG_BACKUP_SEMANTICS flag set.
The error coming back isn't really ACCESS DENIED from what I can tell, 0x1f is error 31 which on Windows means A device attached to the system is not functioning.
Docker Info
Containers: 0
Running: 0
Paused: 0
Stopped: 0
Images: 0
Server Version: 17.06.1-ee-2
Storage Driver: windowsfilter
Windows:
Logging Driver: json-file
Plugins:
Volume: local
Network: l2bridge l2tunnel nat null overlay transparent
Log: awslogs etwlogs fluentd json-file logentries splunk syslog
Swarm: inactive
Default Isolation: process
Kernel Version: 10.0 14393 (14393.1593.amd64fre.rs1_release.170731-1934)
Operating System: Windows Server 2016 Datacenter
OSType: windows
Architecture: x86_64
CPUs: 2
Total Memory: 4GiB
Name: DOCKER1
ID: APE3:7FCF:CXYM:O6IZ:ZSF7:A7ET:7ECL:I22S:VUTT:Y6TH:J3WP:UH3S
Docker Root Dir: D:\
Debug Mode (client): false
Debug Mode (server): true
File Descriptors: -1
Goroutines: 24
System Time: 2017-09-11T08:24:14.3674638-04:00
EventsListeners: 0
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false
Client Error
Using default tag: latest
latest: Pulling from microsoft/nanoserver
bce2fbc256ea: Extracting [==================================================>] 252.7MB/252.7MB
38cc73423ca1: Download complete
failed to register layer: re-exec error: exit status 1: output: Failed to OpenForBackup failed in Win32: open \\?\D:\windowsfilter\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\Files: Access is denied. (0x1f) \\?\D:\windowsfilter\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\Files
Server Error
time="2017-09-11T08:17:39.247352000-04:00" level=debug msg="Calling POST /v1.30/images/create?fromImage=microsoft%2Fnanoserver&tag=latest"
time="2017-09-11T08:17:39.251352100-04:00" level=debug msg="Trying to pull microsoft/nanoserver from https://registry-1.docker.io v2"
time="2017-09-11T08:17:39.735384400-04:00" level=debug msg="Pulling ref from V2 registry: microsoft/nanoserver:latest"
time="2017-09-11T08:17:40.011401200-04:00" level=debug msg="pulling blob \"sha256:bce2fbc256ea437a87dadac2f69aabd25bed4f56255549090056c1131fad0277\""
time="2017-09-11T08:17:40.017402000-04:00" level=debug msg="pulling blob \"sha256:38cc73423ca1d089e2e2374a8baf65d25d3792b22a22263c702f22f85bea6d4c\""
time="2017-09-11T08:17:40.157413400-04:00" level=debug msg="Pulling sha256:bce2fbc256ea437a87dadac2f69aabd25bed4f56255549090056c1131fad0277 from foreign URL https://go.microsoft.com/fwlink/?linkid=837858"
time="2017-09-11T08:17:40.163416100-04:00" level=debug msg="Pulling sha256:38cc73423ca1d089e2e2374a8baf65d25d3792b22a22263c702f22f85bea6d4c from foreign URL https://go.microsoft.com/fwlink/?linkid=854454"
time="2017-09-11T08:17:52.198201200-04:00" level=debug msg="Downloaded 38cc73423ca1 to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\GetImageBlob161053273"
time="2017-09-11T08:17:57.111523500-04:00" level=debug msg="Downloaded bce2fbc256ea to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\GetImageBlob111832674"
time="2017-09-11T08:17:57.112523700-04:00" level=debug msg="hcsshim::CreateLayer Flavour 1 ID 6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5 parent "
time="2017-09-11T08:17:57.116533100-04:00" level=debug msg="hcsshim::CreateLayer - succeeded id=6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5 parent= flavour=1"
time="2017-09-11T08:17:57.211536900-04:00" level=debug msg="Cleaning up layer 6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5: re-exec error: exit status 1: output: Failed to OpenForBackup failed in Win32: open \\\\?\\D:\\windowsfilter\\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\\Files: Access is denied. (0x1f) \\\\?\\D:\\windowsfilter\\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\\Files"
time="2017-09-11T08:17:57.212531300-04:00" level=debug msg="HCSShim::GetContainers query={}"
time="2017-09-11T08:17:57.215532100-04:00" level=debug msg="HCSShim::GetContainers succeeded"
time="2017-09-11T08:17:57.217532400-04:00" level=debug msg="hcsshim::DestroyLayer Flavour 1 ID 6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5-removing"
time="2017-09-11T08:17:57.218532500-04:00" level=debug msg="hcsshim::DestroyLayer succeeded flavour=1 id=6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5-removing"
time="2017-09-11T08:17:57.242531800-04:00" level=info msg="Attempting next endpoint for pull after error: failed to register layer: re-exec error: exit status 1: output: Failed to OpenForBackup failed in Win32: open \\\\?\\D:\\windowsfilter\\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\\Files: Access is denied. (0x1f) \\\\?\\D:\\windowsfilter\\6fb4dead64f434a0265b84a01d09d3bb268325b2a7d9c83c05adbd1f2836efc5\\Files"
Server Error with DOCKER_WINDOWSFILTER_NOREEXEC=1
This error is inconsistent, sometimes it is this ones, other times it is just the normal Server Error, and then sometimes another type of crash dump.
time="2017-09-11T08:49:35.685187900-04:00" level=debug msg="Calling POST /v1.30/images/create?fromImage=microsoft%2Fnanoserver&tag=latest"
time="2017-09-11T08:49:35.686188800-04:00" level=debug msg="Trying to pull microsoft/nanoserver from https://registry-1.docker.io v2"
time="2017-09-11T08:49:36.247231600-04:00" level=debug msg="Pulling ref from V2 registry: microsoft/nanoserver:latest"
time="2017-09-11T08:49:36.521247600-04:00" level=debug msg="pulling blob \"sha256:bce2fbc256ea437a87dadac2f69aabd25bed4f56255549090056c1131fad0277\""
time="2017-09-11T08:49:36.525247000-04:00" level=debug msg="pulling blob \"sha256:38cc73423ca1d089e2e2374a8baf65d25d3792b22a22263c702f22f85bea6d4c\""
time="2017-09-11T08:49:36.661266800-04:00" level=debug msg="Pulling sha256:bce2fbc256ea437a87dadac2f69aabd25bed4f56255549090056c1131fad0277 from foreign URL https://go.microsoft.com/fwlink/?linkid=837858"
time="2017-09-11T08:49:36.666257500-04:00" level=debug msg="Pulling sha256:38cc73423ca1d089e2e2374a8baf65d25d3792b22a22263c702f22f85bea6d4c from foreign URL https://go.microsoft.com/fwlink/?linkid=854454"
time="2017-09-11T08:49:50.172222700-04:00" level=debug msg="Downloaded 38cc73423ca1 to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\GetImageBlob288492522"
time="2017-09-11T08:49:55.708618200-04:00" level=debug msg="Downloaded bce2fbc256ea to tempfile C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\\GetImageBlob087154423"
time="2017-09-11T08:49:55.710619600-04:00" level=debug msg="hcsshim::CreateLayer Flavour 1 ID b469896485edf681f3f3c60770db6d85c9461fc0c404b910f7b56878f9a17923 parent "
time="2017-09-11T08:49:55.715618800-04:00" level=debug msg="hcsshim::CreateLayer - succeeded id=b469896485edf681f3f3c60770db6d85c9461fc0c404b910f7b56878f9a17923 parent= flavour=1"
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x671a09]
goroutine 99 [running]:
compress/flate.(*Writer).Close(0x0, 0x0, 0x0)
/usr/local/go/src/compress/flate/deflate.go:729 +0x29
compress/gzip.(*Writer).Close(0xc0424228f0, 0x42d066, 0x2102d60)
/usr/local/go/src/compress/gzip/gzip.go:241 +0x73
github.com/docker/docker/layer.(*fileMetadataTransaction).TarSplitWriter.func1(0xc042896be0, 0xc04385f970)
/go/src/github.com/docker/docker/layer/filestore.go:123 +0x48
github.com/docker/docker/pkg/ioutils.(*writeCloserWrapper).Close(0xc0420df2a0, 0x0, 0xc042811ef0)
/go/src/github.com/docker/docker/pkg/ioutils/writers.go:35 +0x32
github.com/docker/docker/layer.(*layerStore).applyTar(0xc042437360, 0x21194e0, 0xc042c0aa80, 0x24987b0, 0xc0420dee00, 0x0, 0x0, 0xc04280e460, 0x20f9e00, 0xc04385a9f0)
/go/src/github.com/docker/docker/layer/layer_store.go:237 +0x3c1
github.com/docker/docker/layer.(*layerStore).registerWithDescriptor(0xc042437360, 0x24987b0, 0xc0420dee00, 0x0, 0x0, 0xc042234c00, 0x39, 0xf0fc23a, 0xc042cbbe00, 0x47, ...)
/go/src/github.com/docker/docker/layer/layer_store.go:313 +0x36c
github.com/docker/docker/layer.(*layerStore).RegisterWithDescriptor(0xc042437360, 0x24987b0, 0xc0420dee00, 0x0, 0x0, 0xc042234c00, 0x39, 0xf0fc23a, 0xc042cbbe00, 0x47, ...)
/go/src/github.com/docker/docker/layer/layer_store_windows.go:10 +0x9b
github.com/docker/docker/distribution/xfer.(*LayerDownloadManager).makeDownloadFunc.func1.1(0xc0423f6ba0, 0xc0423f6a80, 0x2114300, 0xc042720000, 0x0, 0xc0420e1d80, 0xc04245a3c0, 0xc0423f6b40, 0xc042d032e0)
/go/src/github.com/docker/docker/distribution/xfer/download.go:338 +0xcfe
created by github.com/docker/docker/distribution/xfer.(*LayerDownloadManager).makeDownloadFunc.func1
/go/src/github.com/docker/docker/distribution/xfer/download.go:366 +0x161
The other observed crash dump has the same previous lines.
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x671919]
goroutine 228 [running]:
compress/flate.(*Writer).Write(0x0, 0xc0420ad600, 0x825, 0xd00, 0xd00, 0xc06ed82b64, 0xc042c79e40)
/usr/local/go/src/compress/flate/deflate.go:709 +0x29
compress/gzip.(*Writer).Write(0xc043793290, 0xc0420ad600, 0x825, 0xd00, 0xc042c79e40, 0x1, 0x824)
/usr/local/go/src/compress/gzip/gzip.go:196 +0xd0
github.com/docker/docker/pkg/ioutils.(*writeCloserWrapper).Write(0xc0423d93c0, 0xc0420ad600, 0x825, 0xd00, 0x0, 0x0, 0xc042eebcb0)
<autogenerated>:63 +0x72
encoding/json.(*Encoder).Encode(0xc04242a2d0, 0x172ec60, 0xc042482d80, 0xc042482d80, 0x0)
/usr/local/go/src/encoding/json/stream.go:218 +0x1f6
github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/storage.(*jsonPacker).AddEntry(0xc042ebe480, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xc042342880, 0x600, ...)
/go/src/github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/storage/packer.go:97 +0x1b8
github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/asm.NewInputTarStream.func1(0x20fbec0, 0xc0423d93e0, 0xc042004820, 0x20fb6c0, 0xc042ebe480, 0x20fb680, 0x21a3c38)
/go/src/github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/asm/disassemble.go:78 +0x494
created by github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/asm.NewInputTarStream
/go/src/github.com/docker/docker/vendor/github.com/vbatts/tar-split/tar/asm/disassemble.go:138 +0x1ba
FLTMC INSTANCES
Filter Volume Name Altitude Instance Name Frame SprtFtrs VlStatus
-------------------- ------------------------------------- ------------ ---------------------- ----- -------- --------
Wof C: 40700 Wof Instance 0 00000003
npsvctrig \Device\NamedPipe 46000 npsvctrig 0 00000000
daemon.json
{
"data-root": "D:\\",
"tlsverify": true,
"tlskey": "C:\\ProgramData\\docker\\cert.d\\key.pem",
"tlscacert": "C:\\ProgramData\\docker\\cert.d\\ca.pem",
"hosts": [
"npipe://",
"tcp://0.0.0.0:2376"
],
"tlscert": "C:\\ProgramData\\docker\\cert.d\\cert.pem"
}
You should check out this bug I opened on the moby project for this issue. I determined that this behavior occurs when running Windows Server 2016 with the Desktop Experience on a VM hosted on VMWare ESXi. Interestingly enough, it doesn't occur on a bare metal machine when running with the Desktop experience. My recommendation, run Windows Server Core. Desktop Experience & docker don't mix well.
https://github.com/moby/moby/issues/34807
Also, you may want to run the Windows Temp Directory on the same drive you have your Docker Data Root. We have noticed some funkiness when they are not on the same drive.