LCOW: Docker Volumes don't support some fs operations that bind mounts support - CreateFile access denied

[Iristyle]

Launching Postgres Linux container under RS5 / 19H1 with a Docker bind mount works, but fails when a Docker volume is used.

Bind mount successful example

md c:\windows\temp\data
docker run --mount type=bind,source=c:\windows\temp\data,target=/var/lib/postgresql/data postgres:9.6

Startup logs

The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default timezone ... Etc/UTC
selecting dynamic shared memory implementation ... posix
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ...
WARNING: enabling "trust" authentication for local connections
You can change this by editing pg_hba.conf or using the option -A, or
--auth-local and --auth-host, the next time you run initdb.
ok

Success. You can now start the database server using:

    pg_ctl -D /var/lib/postgresql/data -l logfile start

****************************************************
WARNING: No password has been set for the database.
         This will allow anyone with access to the
         Postgres port to access your database. In
         Docker's default configuration, this is
         effectively any other container on the same
         system.

         Use "-e POSTGRES_PASSWORD=password" to set
         it in "docker run".
****************************************************
waiting for server to start....LOG:  database system was shut down at 2019-08-27 21:52:00 UTC
LOG:  MultiXact member wraparound protections are now enabled
LOG:  autovacuum launcher started
LOG:  database system is ready to accept connections
 done
server started

/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*

waiting for server to shut down...LOG:  received fast shutdown request
LOG:  aborting any active transactions
LOG:  autovacuum launcher shutting down
LOG:  shutting down
.LOG:  database system is shut down
 done
server stopped

PostgreSQL init process complete; ready for start up.

LOG:  database system was shut down at 2019-08-27 21:52:07 UTC
LOG:  MultiXact member wraparound protections are now enabled
LOG:  autovacuum launcher started
LOG:  database system is ready to accept connections

Volume failure example

Don't explicitly create / specify a volume so that an anonymous volume is created. The behavior is the same when manually creating a named volume with docker volume create pg and instead calling docker run --volume pg:/var/lib/postgresql/data postgres:9.6

docker run postgres:9.6

Startup logs

The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default timezone ... Etc/UTC
selecting dynamic shared memory implementation ... posix
creating configuration files ... ok
running bootstrap script ... LOG:  could not link file "pg_xlog/xlogtemp.33" to "pg_xlog/000000010000000000000001": Permission denied
FATAL:  could not open file "pg_xlog/000000010000000000000001": No such file or directory
child process exited with exit code 1
initdb: removing contents of data directory "/var/lib/postgresql/data"

Environment info

docker version

Client:
 Version:           master-dockerproject-2019-08-01
 API version:       1.40
 Go version:        go1.12.7
 Git commit:        e505a7c2
 Built:             Fri Aug  2 00:02:45 2019
 OS/Arch:           windows/amd64
 Experimental:      false

Server:
 Engine:
  Version:          master-dockerproject-2019-08-01
  API version:      1.41 (minimum version 1.24)
  Go version:       go1.12.7
  Git commit:       4fb5e9e
  Built:            Fri Aug  2 00:12:20 2019
  OS/Arch:          windows/amd64
  Experimental:     true

docker info

Client:
 Debug Mode: false

Server:
 Containers: 1
  Running: 0
  Paused: 0
  Stopped: 1
 Images: 271
 Server Version: master-dockerproject-2019-08-01
 Storage Driver: windowsfilter (windows) lcow (linux)
  Windows:
  LCOW:
 Logging Driver: json-file
 Plugins:
  Volume: local
  Network: ics internal l2bridge l2tunnel nat null overlay private transparent
  Log: awslogs etwlogs fluentd gcplogs gelf json-file local logentries splunk syslog
 Swarm: inactive
 Default Isolation: hyperv
 Kernel Version: 10.0 18362 (18362.1.amd64fre.19h1_release.190318-1202)
 Operating System: Windows 10 Enterprise Version 1903 (OS Build 18362.295)
 OSType: windows
 Architecture: x86_64
 CPUs: 2
 Total Memory: 16GiB
 Name: ci-lcow-prod-4
 ID: F4O4:AX7K:ES5U:EQ74:2VJW:HZ2J:6TJK:474M:Q35F:RT2M:UGBW:PW5W
 Docker Root Dir: C:\ProgramData\docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: true
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

Debugging

I used procmon to trace the API calls through vmwp.exe that seem to cause the specific failure. It appears that CreateFile is passed the same arguments in both cases, but gets access denied when a volume is used, but is successful with a bind mount:

Desired Access:	Write Data/Add File, Synchronize
Disposition:	Open
Options:	
Attributes:	n/a
ShareMode:	Read, Write
AllocationSize:	n/a
OpenResult:	Opened

The stack trace for that API call is

"Frame","Module","Location","Address","Path"
"0","FLTMGR.SYS","FltDecodeParameters + 0x1cfd","0xfffff8010c72aa5d","C:\WINDOWS\System32\drivers\FLTMGR.SYS"
"1","FLTMGR.SYS","FltDecodeParameters + 0x1840","0xfffff8010c72a5a0","C:\WINDOWS\System32\drivers\FLTMGR.SYS"
"2","FLTMGR.SYS","FltQueryInformationFile + 0x963","0xfffff8010c762d13","C:\WINDOWS\System32\drivers\FLTMGR.SYS"
"3","ntoskrnl.exe","IofCallDriver + 0x59","0xfffff8010e231819","C:\WINDOWS\system32\ntoskrnl.exe"
"4","ntoskrnl.exe","KeInitializeEvent + 0x64","0xfffff8010e2308c4","C:\WINDOWS\system32\ntoskrnl.exe"
"5","ntoskrnl.exe","SeSetAccessStateGenericMapping + 0x81b","0xfffff8010e7e3e1b","C:\WINDOWS\system32\ntoskrnl.exe"
"6","ntoskrnl.exe","FsRtlIsEcpAcknowledged + 0xd7","0xfffff8010e8ba8d7","C:\WINDOWS\system32\ntoskrnl.exe"
"7","ntoskrnl.exe","SeUnlockSubjectContext + 0x85f","0xfffff8010e7eadef","C:\WINDOWS\system32\ntoskrnl.exe"
"8","ntoskrnl.exe","ObOpenObjectByNameEx + 0x201","0xfffff8010e7e9251","C:\WINDOWS\system32\ntoskrnl.exe"
"9","ntoskrnl.exe","NtCreateFile + 0x8b0","0xfffff8010e82dd50","C:\WINDOWS\system32\ntoskrnl.exe"
"10","ntoskrnl.exe","IoCreateFileEx + 0x11d","0xfffff8010e82d3fd","C:\WINDOWS\system32\ntoskrnl.exe"
"11","ntoskrnl.exe","FsRtlCancellableWaitForSingleObject + 0x1d9","0xfffff8010e8d4f49","C:\WINDOWS\system32\ntoskrnl.exe"
"12","ntoskrnl.exe","NtSetInformationFile + 0xacf","0xfffff8010e22922f","C:\WINDOWS\system32\ntoskrnl.exe"
"13","ntoskrnl.exe","setjmpex + 0x7b95","0xfffff8010e3d1515","C:\WINDOWS\system32\ntoskrnl.exe"
"14","ntoskrnl.exe","KeSynchronizeExecution + 0x2c30","0xfffff8010e3c3b00","C:\WINDOWS\system32\ntoskrnl.exe"
"15","storvsp.sys","VstorSendNotification + 0x1751a","0xfffff80e001aec7a","C:\WINDOWS\System32\drivers\storvsp.sys"
"16","storvsp.sys","VstorSendNotification + 0x1606e","0xfffff80e001ad7ce","C:\WINDOWS\System32\drivers\storvsp.sys"
"17","storvsp.sys","VstorSendNotification + 0xe13f","0xfffff80e001a589f","C:\WINDOWS\System32\drivers\storvsp.sys"
"18","ntoskrnl.exe","NtDeviceIoControlFile + 0x78b","0xfffff8010e7e6b2b","C:\WINDOWS\system32\ntoskrnl.exe"
"19","ntoskrnl.exe","NtDeviceIoControlFile + 0x56","0xfffff8010e7e63f6","C:\WINDOWS\system32\ntoskrnl.exe"
"20","ntoskrnl.exe","setjmpex + 0x7b95","0xfffff8010e3d1515","C:\WINDOWS\system32\ntoskrnl.exe"
"21","ntdll.dll","ZwDeviceIoControlFile + 0x14","0x7ffed975c144","C:\Windows\System32\ntdll.dll"
"22","vp9fs.dll","CreatePlan9FileSystem + 0x2338","0x7ffec1b88e78","C:\Windows\System32\vp9fs.dll"
"23","vp9fs.dll","CreatePlan9FileSystem + 0x28cf","0x7ffec1b8940f","C:\Windows\System32\vp9fs.dll"
"24","vp9fs.dll","vp9fs.dll + 0x11f45","0x7ffec1b81f45","C:\Windows\System32\vp9fs.dll"
"25","vp9fs.dll","vp9fs.dll + 0x91da","0x7ffec1b791da","C:\Windows\System32\vp9fs.dll"
"26","vp9fs.dll","CreatePlan9FileSystem + 0x8abb","0x7ffec1b8f5fb","C:\Windows\System32\vp9fs.dll"
"27","vp9fs.dll","CreatePlan9FileSystem + 0x88f3","0x7ffec1b8f433","C:\Windows\System32\vp9fs.dll"
"28","vp9fs.dll","vp9fs.dll + 0xcec2","0x7ffec1b7cec2","C:\Windows\System32\vp9fs.dll"
"29","vp9fs.dll","CreatePlan9FileSystem + 0xe9a6","0x7ffec1b954e6","C:\Windows\System32\vp9fs.dll"
"30","vp9fs.dll","CreatePlan9FileSystem + 0xdb28","0x7ffec1b94668","C:\Windows\System32\vp9fs.dll"
"31","vp9fs.dll","vp9fs.dll + 0x69fb","0x7ffec1b769fb","C:\Windows\System32\vp9fs.dll"
"32","vp9fs.dll","CreatePlan9FileSystem + 0x12f90","0x7ffec1b99ad0","C:\Windows\System32\vp9fs.dll"
"33","vp9fs.dll","CreatePlan9FileSystem + 0x127ac","0x7ffec1b992ec","C:\Windows\System32\vp9fs.dll"
"34","vp9fs.dll","vp9fs.dll + 0xb1bb","0x7ffec1b7b1bb","C:\Windows\System32\vp9fs.dll"
"35","vp9fs.dll","CreatePlan9FileSystem + 0x941b","0x7ffec1b8ff5b","C:\Windows\System32\vp9fs.dll"
"36","vp9fs.dll","CreatePlan9FileSystem + 0x90d6","0x7ffec1b8fc16","C:\Windows\System32\vp9fs.dll"
"37","vp9fs.dll","vp9fs.dll + 0xb30e","0x7ffec1b7b30e","C:\Windows\System32\vp9fs.dll"
"38","vp9fs.dll","CreatePlan9FileSystem + 0x9d21","0x7ffec1b90861","C:\Windows\System32\vp9fs.dll"
"39","vp9fs.dll","vp9fs.dll + 0x4b46","0x7ffec1b74b46","C:\Windows\System32\vp9fs.dll"
"40","vp9fs.dll","CreatePlan9FileSystem + 0x181b","0x7ffec1b8835b","C:\Windows\System32\vp9fs.dll"
"41","KernelBase.dll","VirtualProtect + 0xc0","0x7ffed69f4ee0","C:\Windows\System32\KernelBase.dll"
"42","ntdll.dll","TpCallbackIndependent + 0x553","0x7ffed96f3713","C:\Windows\System32\ntdll.dll"
"43","ntdll.dll","RtlInitializeResource + 0x872","0x7ffed96f4152","C:\Windows\System32\ntdll.dll"
"44","kernel32.dll","BaseThreadInitThunk + 0x14","0x7ffed8827bd4","C:\Windows\System32\kernel32.dll"
"45","ntdll.dll","RtlUserThreadStart + 0x21","0x7ffed972ce71","C:\Windows\System32\ntdll.dll"

Here's a procmon screenshot showing the sequence of API calls leading to the failures is pretty similar until the access denied

Complete logs available in https://gist.github.com/Iristyle/f4867a954ab7545f38c030e4d91ef511

Postgres Info

Postgres is running the command eval 'initdb --username="$POSTGRES_USER" --pwfile=<(echo "$POSTGRES_PASSWORD") '"$POSTGRES_INITDB_ARGS" in the container at the time of failure: https://github.com/docker-library/postgres/blob/master/docker-entrypoint.sh#L75

Which I believe is originating from https://github.com/postgres/postgres/blob/REL9_6_STABLE/src/bin/initdb/initdb.c#L3260

And ultimately originates from the Postgres function durable_link_or_rename at https://github.com/postgres/postgres/blob/REL9_6_STABLE/src/backend/storage/file/fd.c#L707

See also the related docker-library/postgres#253

[Iristyle]

Left the same comment on the Moby issue:

I should have paid closer attention to the "access denied" error that came back in my trace. Turns out this is permissions related and should hopefully be pretty straightforward to address (just need to find the least privilege to be granted, noting that NTFS junctions historically required admin privileges in Windows, and that changed a bit in Windows 10 - see https://blogs.windows.com/windowsdeveloper/2016/12/02/symlinks-windows-10/)

Create the volume

PS C:\WINDOWS\system32> docker volume create pg
pg

Find the volume location on disk

PS C:\WINDOWS\system32> docker volume inspect pg
[
    {
        "CreatedAt": "2019-09-13T16:38:28-07:00",
        "Driver": "local",
        "Labels": {},
        "Mountpoint": "C:\\ProgramData\\docker\\volumes\\pg\\_data",
        "Name": "pg",
        "Options": {},
        "Scope": "local"
    }
]

Get current permissions

PS C:\WINDOWS\system32> icacls C:\\ProgramData\\docker\\volumes\\pg\\_data
C:\\ProgramData\\docker\\volumes\\pg\\_data BUILTIN\Administrators:(I)(OI)(CI)(F)
                                            NT AUTHORITY\SYSTEM:(I)(OI)(CI)(F)
                                            CI-LCOW-PROD-4\puppet:(I)(OI)(CI)(F)

Successfully processed 1 files; Failed processing 0 files

Grant Full permissions to the Windows users group

PS C:\WINDOWS\system32> icacls C:\\ProgramData\\docker\\volumes\\pg\\_data /grant Users:"(OI)(CI)F" /T
processed file: C:\\ProgramData\\docker\\volumes\\pg\\_data
Successfully processed 1 files; Failed processing 0 files

And read them back

PS C:\WINDOWS\system32> icacls C:\\ProgramData\\docker\\volumes\\pg\\_data
C:\\ProgramData\\docker\\volumes\\pg\\_data BUILTIN\Users:(OI)(CI)(F)
                                            BUILTIN\Administrators:(I)(OI)(CI)(F)
                                            NT AUTHORITY\SYSTEM:(I)(OI)(CI)(F)
                                            CI-LCOW-PROD-4\puppet:(I)(OI)(CI)(F)

Successfully processed 1 files; Failed processing 0 files

Start Postgres with the named volume

PS C:\WINDOWS\system32> docker run --volume pg:/var/lib/postgresql/data postgres:9.6

Postgres output - success!

The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default timezone ... Etc/UTC
selecting dynamic shared memory implementation ... posix
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

Success. You can now start the database server using:

<snip startup stuff/>

PostgreSQL init process complete; ready for start up.

LOG:  database system was shut down at 2019-09-13 23:40:07 UTC
LOG:  MultiXact member wraparound protections are now enabled
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started

[Snipx]

Wow @Iristyle you're a rockstar! Thanks so much for sharing your results. I was having the exact same problem and I would certainly give up before finding the way you came up with!