microsoft / opengcs Goto Github PK

Moved to https://github.com/microsoft/hcsshim/tree/master/internal/guest. If you wish to open PRs/submit issues please do so against https://github.com/microsoft/hcsshim.

License: MIT License

Go 94.29% Makefile 0.87% C 4.53% Shell 0.31%

opengcs's Introduction

Archived

This project has been archived. Its contents have been merged into Microsoft/hcsshim where development will continue. Some code organization has changed as part of the merge, please see below for details on where things have moved. Any issues regarding opengcs should be opened on the hcsshim repo.

Changes:

Everything in /internal has been moved to github.com/Microsoft/hcsshim/internal/guest besides a few redundant packages that had equivalents in hcsshim. These include /internal/debug, /internal/oc and /internal/log. These are now located at github.com/Microsoft/hcsshim/internal/debug, github.com/Microsoft/hcsshim/internal/oc, and github.com/Microsoft/hcsshim/internal/log.
/service/libs/commonutils has moved to github.com/Microsoft/hcsshim/internal/guest.
Any non Go code lives at the root of github.com/Microsoft/hcsshim now, just as it did in this repository. This includes /vsockexec, /init, and /hack.
The main gcs and gcstools binaries are now built and located at github.com/Microsoft/hcsshim/cmd/gcs and github.com/Microsoft/hcsshim/cmd/gcstools.
Makefile lives top level at github.com/Microsoft/hcsshim/Makefile and same commands will work to build everything.

Open Guest Compute Service (opengcs)

Open Guest Compute Service is a Linux open source project to further the development of a production quality implementation of Linux Hyper-V containers on Windows (LCOW). It's designed to run inside a custom Linux OS for supporting Linux container payload.

LCOW v1 (deprecated)

The original version of LCOW v1 was designed to run directly through Docker against the HCS (Host Compute Service) on Windows. This workflow is no longer supported by this repository however it has not been intentionally broken. If you would like to continue to use LCOW v1 there is a branch lcow_v1 that is the LKG branch previous to the removal of LCOW v1 from the master branchline. All future efforts are focused on LCOW v2.

LCOW v2

The primary difference between LCOW v1 and LCOW v2 is that v1 was designed to hide the concept of the Utility VM. The caller created a Linux container and operated on the container as if it was natively running on Windows. In the background a lightweight Utility VM was created that actually hosted the container but this was not visible and its resources not controllable via the caller. Although this works, it severely limited certain abilities such as the concept of Kubernetes pod or placing multiple LCOW containers in a single hypervisor boundary and set of resources.

Thus LCOW v2 was created which has two primary differences.

The Utility VM backing the Linux containers is a first class construct. Thus it can be managed in a lifetime separate from the actual containers running in it.
The communication from host to guest is no longer done via the platform. This means that LCOW v2 can iterate simply by improving its host/guest protocol with no need for taking Windows updates.

The focus of LCOW v2 as a replacement of LCOW v1 is through the coordination and work that has gone into containerd/containerd and its Runtime V2 interface. To see our containerd hostside shim please look here Microsoft/hcsshim/cmd/containerd-shim-runhcs-v1.

Contributing

This project welcomes contributions and suggestions. Most contributions require you to agree to a Contributor License Agreement (CLA) declaring that you have the right to, and actually do, grant us the rights to use your contribution. For details, visit https://cla.microsoft.com.

When you submit a pull request, a CLA-bot will automatically determine whether you need to provide a CLA and decorate the PR appropriately (e.g., label, comment). Simply follow the instructions provided by the bot. You will only need to do this once across all repos using our CLA.

We also ask that contributors sign their commits using git commit -s or git commit --signoff to certify they either authored the work themselves or otherwise have permission to use it in this project.

Code of Conduct

This project has adopted the Microsoft Open Source Code of Conduct. For more information see the Code of Conduct FAQ or contact [email protected] with any additional questions or comments.

opengcs's People

Contributors

Stargazers

Watchers

opengcs's Issues

Consolidate errors in GCS

We want to remove any of the calls to utils.Log or utils.LogMsg in the GCS (under service/gcs), and replace them with calls to logrus. This makes for a more unified logging experience in the GCS.

We'll also want to change the logrus logging location to the location passed into the GCS as an argument. We can do this by removing ProcessCommandlineOptions and putting the equivalent functionality into a function in the GCS's main.go file. We can then switch to using the value passed as a commandline argument rather than the hard-coded "/tmp/logrus.log".

initrd size grew between 7/3 and ~7/7 by 1.5MB

As sent via email to Cheng-mean, Ben, Akash & John, but no-one replied. Hence logging it here as an issue.

On 7/7 I noticed that it had increased by ~1.5MB. Currently (7/13) it is 9.5M. On 7/3 (master build 411) it was 'only' 8MB.

Support AttachOnly flag in MappedVirtualDisk

We only want to actually mount (and unmount) mapped virtual disks if the AttachOnly flag is false. Basic work is currently in the disk_attach_only branch. Still to do is:

Don't even bother keeping track of disks where AttachOnly is true, so that the if guard in the unmount call is unnecessary
Add tests
- Just include the AttachOnly field in bridge_test.go and gcs_test.go
- Test behavior when AttachOnly is true in storage_test.go

log commands and stdout/stderr

I was debugging an issue with LCOW and it seems that gcs is shelling out to a number of commands inside the utility VM. It would be useful for debug if the code would log:

the full command line of commands executed
the stdout and stderr of the command

apt-get doesn't work on ubuntu:latest

apt-get isn't working on ubuntu:latest. Seems like something to do with DNS.

Interestingly enough, it's working in ubuntu:trusty

Not updating MTU for networking in overlay mode

In the Windows GCS, we update the MTU if a non-zero EncapOverhead is passed in the adapter settings. We're not doing this here (and in fact EncapOverhead is not currently defined in the Go struct).

Per-process and per-container directories are no longer necessary

I don't think there's any state in these directories that isn't also in gcs memory. We can stop using these directories and simplify a lot of code.

Fully merge GCS and runC wrapper code

There isn't a compelling enough reason to keep the runC wrapper code separate from the GCS code. It should be merged so it can depend on the Core code performing initial setup. The files under /var/run/gcsrunc should also be moved under /tmp/gcs.

/etc/resolv.conf not getting populated in ubuntu image

docker run --rm ubuntu cat /etc/resolv.conf

No output. This breaks DNS resolution inside containers.

Incorrect erroring when command is not available in container

For example, the busybox image doesn't have bash (it does have sh). If started with command that's not available, we should return a clean error to that effect. Example:

docker -H "npipe:////./pipe//docker_lcow" run -ti busybox
 bash
C:\Program Files\Docker\Docker\Resources\bin\docker.exe: Error response from daemon: container 8693b3b051b30d36c7fe19589746b46064168d8466b43c36ded2ea4139a80541 encountered an error during CreateProcess: failure in a Windows system call: Unspecified error (0x80004005) extra info: {"CommandArgs":["bash"],"WorkingDirectory":"/","Environment":{"HOSTNAME":"8693b3b051b3","PATH":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin","TERM":"xterm"},"EmulateConsole":true,"CreateStdInPipe":true,"CreateStdOutPipe":true,"ConsoleSize":
[snip]

For comparison:

docker run -ti busybox bash
C:\Program Files\Docker\Docker\Resources\bin\docker.exe: Error response from daemon: oci runtime error: container_linux.go:265: starting container process caused "exec: \"bash\": executable file not found in $PATH".

This is with a (otherwise) working system set up like this: docker run -ti busybox bash
C:\Program Files\Docker\Docker\Resources\bin\docker.exe: Error response from daemon: oci runtime error: container_linux.go:265: starting container process caused "exec: "bash": executable file not found in $PATH".

Intermittent failures on docker pull (block devices not present)

[I think this is a known issue, but could not find an issue tracking it]

docker pull busybox or docker pull alpine fail intermittently on a fresh start (with the c:\lcow directory empty.

This is with:

OpenGCS commit: 203a54283e0b0d58c1bc9d8d0f0b4bea8503fe37
dockerd commit: 0dbc182b6
LinuxKit kernel 4.11.1

I've seen two types of error messages (see below), both related to block devices for layers not being present.

failed to 'ls /sys/bus/scsi/devices/0:0:0:2/block':

C:\Users\rneugeba\Desktop\docker\docker.exe: failed to register layer: failed to create SVM scratch VHDX (applydiff e7b97c3c849c8c1e46023e68798d10075375068d4b11651400252fbe2e296dd1): failed to `ls /sys/bus/scsi/devices/0:0:0:2/block` following hot-add C:\lcow\lcow\scratch\e7b97c3c849c8c1e46023e68798d10075375068d4b11651400252fbe2e296dd1.vhdx to utility VM: failed to create process (&{Options:{KirdPath:C:\Program Files\Linux Containers KernelFile:bootx64.efi InitrdFile:initrd.img Vhdx:C:\Program Files\Linux Containers\uvm.vhdx TimeoutSeconds:0 BootParameters:} Name:e7b97c3c849c8c1e46023e68798d10075375068d4b11651400252fbe2e296dd1_svm RequestedMode:3 ActualMode:2 UvmTimeoutSeconds:300 Uvm:0xc042966300 MappedVirtualDisks:[]}) in utility VM: container e7b97c3c849c8c1e46023e68798d10075375068d4b11651400252fbe2e296dd1_svm encountered an error during CreateProcess: failure in a Windows system call: Unspecified error (0x80004005) extra info: {"CommandLine":"ls /sys/bus/scsi/devices/0:0:0:2/block","WorkingDirectory":"/bin","Environment":{"PATH":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:"},"CreateStdInPipe":true,"CreateStdOutPipe":true,"CreateStdErrPipe":true,"ConsoleSize":[0,0],"CreateInUtilityVm":true}.

"mkfs.ext4 -q -E lazy_itable_init=1 -O ^has_journal,sparse_super2,uninit_bg,^resize_inode /dev/sda" failing

C:\Users\rneugeba\Desktop\docker\docker.exe: failed to register layer: failed to create SVM scratch VHDX (applydiff 8a461f34126ea60d11f66bf68679d4e53b3de4fa34a590c8e8d401daff8349ab): failed to RunProcess "C:\\lcow\\lcow\\scratch\\8a461f34126ea60d11f66bf68679d4e53b3de4fa34a590c8e8d401daff8349ab.vhdx" following hot-add mkfs.ext4 -q -E lazy_itable_init=1 -O ^has_journal,sparse_super2,uninit_bg,^resize_inode /dev/sda to utility VM: failed to create process (&{Options:{KirdPath:C:\Program Files\Linux Containers KernelFile:bootx64.efi InitrdFile:initrd.img Vhdx:C:\Program Files\Linux Containers\uvm.vhdx TimeoutSeconds:0 BootParameters:} Name:8a461f34126ea60d11f66bf68679d4e53b3de4fa34a590c8e8d401daff8349ab_svm RequestedMode:3 ActualMode:2 UvmTimeoutSeconds:300 Uvm:0xc04297ca80 MappedVirtualDisks:[]}) in utility VM: container 8a461f34126ea60d11f66bf68679d4e53b3de4fa34a590c8e8d401daff8349ab_svm encountered an error during CreateProcess: failure in a Windows system call: Unspecified error (0x80004005) extra info: {"CommandLine":"mkfs.ext4 -q -E lazy_itable_init=1 -O ^has_journal,sparse_super2,uninit_bg,^resize_inode /dev/sda","WorkingDirectory":"/bin","Environment":{"PATH":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:"},"CreateStdInPipe":true,"CreateStdOutPipe":true,"CreateStdErrPipe":true,"ConsoleSize":[0,0],"CreateInUtilityVm":true}.

GCS panic

Found this while running some tests. Haven't looked much into it yet.

Avoid fixed paths to executables like runc

gcs hardcodes the location of things like runc. It would be better to use exec.LookPath() allowing people to place the binaries in slightly different locations (but still within PATH)

Cannot remove stopped container

docker -H "npipe:////./pipe//docker_lcow" ps -aq
34efc67b6d1a
8693b3b051b3
bc9fcaa57728
5c9c256eb967
0ecf2d5ec463
42fc2165ae1f
a2d0f894a25e

docker -H "npipe:////./pipe//docker_lcow" rm 34efc67b6d1a

Error response from daemon: driver "lcow" failed to remove root filesystem for 34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824: rename C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824 C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824-removing: Access is denied.

From daemon log:

DEBU[2017-09-17T10:46:40.235184900-07:00] Calling DELETE /v1.31/containers/34efc67b6d1a
DEBU[2017-09-17T10:46:40.247181800-07:00] lcowdriver: remove: id 34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824
DEBU[2017-09-17T10:46:40.247181800-07:00] lcowdriver: remove: id 34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824: layerPath C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824
ERRO[2017-09-17T10:46:40.248180100-07:00] Error removing mounted layer 34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824: rename C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824 C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824-removing: Access is denied.
DEBU[2017-09-17T10:46:40.248180100-07:00] FIXME: Got an API for which error does not match any expected type!!!: rename C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824 C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824-removing: Access is denied.  error_type="*os.LinkError" module=api
ERRO[2017-09-17T10:46:40.248180100-07:00] Handler for DELETE /v1.31/containers/34efc67b6d1a returned error: driver "lcow" failed to remove root filesystem for 34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824: rename C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824 C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824-removing: Access is denied.
DEBU[2017-09-17T10:46:40.249178400-07:00] FIXME: Got an API for which error does not match any expected type!!!: rename C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824 C:\lcow4\lcow\34efc67b6d1ae2ea982f232980a700d2b1895e62c8e161e35d44bfafa742e824-removing: Access is denied.  error_type="*os.LinkError" module=api

.\dockerd.exe -v
Docker version master-dockerproject-2017-09-15, build 5c10698

We should unify the runtime.Process and oslayer.Process interfaces

We should unify the runtime.Process and oslayer.Process interfaces to not leak any details about whether or not the process is a container process or a host process given these are the same in Linux. Then we can simplify things like our cache object to simply store the Process rather than the relay etc.

#84 - For reference.

golint issues under service should be addressed

gcs\bridge\bridge.go:44:80: exported func NewBridge returns unexported type *bridge.bridge, which can be annoying to use
gcs\core\gcs\gcs.go:62:55: exported func NewGCSCore returns unexported type *gcs.gcsCore, which can be annoying to use
gcs\errors\errors.go:17:41: exported func NewContainerExistsError returns unexported type *gcs.containerExistsError, which can be annoying to use
gcs\errors\errors.go:31:47: exported func NewContainerDoesNotExistError returns unexported type *gcs.containerDoesNotExistError, which can be annoying to use
gcs\errors\errors.go:45:43: exported func NewProcessDoesNotExistError returns unexported type *gcs.processDoesNotExistError, which can be annoying to use
gcs\oslayer\oslayer.go:17:2: exported const SIGKILL should have comment (or a comment on this block) or be unexported
gcs\oslayer\mockos\mockos.go:21:31: exported func NewMockReadWriteCloser returns unexported type *mockos.mockReadWriteCloser, which can be annoying to use
gcs\oslayer\mockos\mockos.go:40:40: exported func NewProcessExitState returns unexported type *mockos.mockProcessExitState, which can be annoying to use
gcs\oslayer\mockos\mockos.go:256:14: exported func NewOS returns unexported type *mockos.mockOS, which can be annoying to use
gcs\oslayer\realos\realos.go:29:50: exported func NewProcessExitState returns unexported type *realos.realProcessExitState, which can be annoying to use
gcs\oslayer\realos\realos.go:246:14: exported func NewOS returns unexported type *realos.realOS, which can be annoying to use
gcs\prot\protocol.go:40:2: exported const MtNone should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:51:2: exported const McNone should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:66:2: exported const MiNone should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:68:2: comment on exported const ComputeSystemCreateV1 should be of the form "ComputeSystemCreateV1 ..."
gcs\prot\protocol.go:80:2: comment on exported const ComputeSystemResponseCreateV1 should be of the form "ComputeSystemResponseCreateV1 ..."
gcs\prot\protocol.go:92:2: comment on exported const ComputeSystemNotificationV1 should be of the form "ComputeSystemNotificationV1 ..."
gcs\prot\protocol.go:149:2: exported const NtNone should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:165:2: exported const AoNone should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:246:2: exported const PtMemory should have comment (or a comment on this block) or be unexported
gcs\prot\protocol.go:263:2: exported const RtAdd should have comment (or a comment on this block) or be unexported
gcs\runtime\mockruntime\mockruntime.go:17:19: exported func NewRuntime returns unexported type *mockruntime.mockRuntime, which can be annoying to use
gcs\runtime\runc\runc.go:36:20: exported func NewRuntime returns unexported type *runc.runcRuntime, which can be annoying to use
gcsutils\fs\ext4.go:35:1: exported method Ext4Fs.CalcRegFileSize should have comment or be unexported
gcsutils\fs\ext4.go:47:1: exported method Ext4Fs.CalcDirSize should have comment or be unexported
gcsutils\fs\ext4.go:55:1: exported method Ext4Fs.CalcSymlinkSize should have comment or be unexported
gcsutils\fs\ext4.go:64:1: exported method Ext4Fs.CalcHardlinkSize should have comment or be unexported
gcsutils\fs\ext4.go:70:1: exported method Ext4Fs.CalcCharDeviceSize should have comment or be unexported
gcsutils\fs\ext4.go:75:1: exported method Ext4Fs.CalcBlockDeviceSize should have comment or be unexported
gcsutils\fs\ext4.go:80:1: exported method Ext4Fs.CalcFIFOPipeSize should have comment or be unexported
gcsutils\fs\ext4.go:85:1: exported method Ext4Fs.CalcSocketSize should have comment or be unexported
gcsutils\fs\ext4.go:90:1: exported method Ext4Fs.CalcAddExAttrSize should have comment or be unexported
gcsutils\fs\ext4.go:95:1: exported method Ext4Fs.FinalizeSizeContext should have comment or be unexported
gcsutils\fs\ext4.go:109:1: exported method Ext4Fs.GetSizeInfo should have comment or be unexported
gcsutils\fs\ext4.go:113:1: exported method Ext4Fs.CleanupSizeContext should have comment or be unexported
gcsutils\fs\ext4.go:118:1: exported method Ext4Fs.MakeFileSystem should have comment or be unexported
gcsutils\fs\ext4.go:141:1: exported method Ext4Fs.MakeBasicFileSystem should have comment or be unexported
gcsutils\gcstools\createSandbox.go:12:7: exported const PreBuiltSandboxFile should have comment or be unexported
gcsutils\gcstools\createSandbox.go:40:6: don't use underscores in Go names; func createSandbox_main should be createSandboxMain
gcsutils\gcstools\exportSandbox.go:50:6: don't use underscores in Go names; func exportSandbox_main should be exportSandboxMain
gcsutils\gcstools\main.go:29:9: should omit 2nd value from range; this loop is equivalent to `for k := range ...`
gcsutils\gcstools\tar2vhd_main.go:37:6: don't use underscores in Go names; func tar2vhd_main should be tar2vhdMain
gcsutils\gcstools\vhd2tar_main.go:35:6: don't use underscores in Go names; func vhd2tar_main should be vhd2tarMain
gcsutils\gcstools\commoncli\common.go:17:1: exported function SetFlagsForTar2VHDLib should have comment or be unexported
gcsutils\gcstools\commoncli\common.go:25:1: exported function SetupTar2VHDLibOptions should have comment or be unexported
gcsutils\gcstools\commoncli\common.go:67:1: exported function SetFlagsForLogging should have comment or be unexported
gcsutils\gcstools\commoncli\common.go:73:1: exported function SetupLogging should have comment or be unexported
gcsutils\libtar2vhd\tar2vhd.go:18:6: exported type Options should have comment or be unexported
gcsutils\libtar2vhd\tar2vhd.go:25:1: exported function Tar2VHD should have comment or be unexported
gcsutils\libtar2vhd\tar2vhd.go:61:1: exported function VHD2Tar should have comment or be unexported
gcsutils\libtar2vhd\tar2vhd.go:101:1: exported function VHDX2Tar should have comment or be unexported
gcsutils\tarlib\tardisk.go:117:1: exported function CreateTarDisk should have comment or be unexported
gcsutils\tarlib\whiteout.go:12:1: exported function CalcWhiteoutSize should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:11:1: comment on exported const CookieMagic should be of the form "CookieMagic ..."
gcsutils\vhd\fixed_vhd_header.go:13:7: exported const FeatureMask should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:14:7: exported const FileFormatVersionMagic should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:15:7: exported const FixedDataOffset should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:16:7: exported const CreatorApplicationMagic should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:17:7: exported const CreatorVersionMagic should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:18:7: exported const CreatorHostOSMagic should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:20:1: comment on exported const DiskTypeNone should be of the form "DiskTypeNone ..."
gcsutils\vhd\fixed_vhd_header.go:23:7: exported const DiskTypeFixed should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:24:7: exported const DiskTypeDynamic should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:25:7: exported const DiskTypeDifferencing should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:27:1: comment on exported const SaveStateYes should be of the form "SaveStateYes ..."
gcsutils\vhd\fixed_vhd_header.go:29:7: exported const SaveStateNo should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:36:7: exported const MaxCHS should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:38:1: comment on exported const TimeStart should be of the form "TimeStart ..."
gcsutils\vhd\fixed_vhd_header.go:63:7: exported const FixedVHDHeaderSize should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:69:1: exported function NewFixedVHDHeader should have comment or be unexported
gcsutils\vhd\fixed_vhd_header.go:100:1: exported method FixedVHDHeader.Bytes should have comment or be unexported
gcsutils\vhd\vhd_converter.go:17:1: exported function NewFixedVHDConverter should have comment or be unexported

Add staged cleanup for calls such as: mountMappedDirectories

We should likely add staged cleanup for multi level operations if a later operation fails. IE: Remove the directory we created if the mount later fails, etc.

Need a `changeSizes` utility to support DiffSize() amd modify

@gupta-ak

Pasting email for now.

For Changes(), for supporting ADD + DELETE only, we can do it without extra functionality. For MODIFY changes, I would probably have to make a changesSize utility.

opengcs should support clean shutdown of the host

Right now, a shutdown request only sends a sigterm on the container ID in the message. Unfortunately, this means there is no way to request a clean shutdown of the host VM. Ideally we'd have some way to perform this operation via the GCS.

WaitProcess should honor TimeoutInMS

We currently don't actually honor the timeout on a wait process call and it will wait forever. If the users passes a timeout we should cancel the wait after that amount of time.

Update runC tests to include stdio and non-sleep processes

Due to a bug I wasn't able to track down, container processes would occasionally exit at random in the test suite. This couldn't be reproed in any other environment than the tests. A workaround was to use only sleep processes in the runC tests. However, some combination of GCS and runC updates seems to have fixed the bug. The tests should now be expanded to include other types of processes than sleep.

mkfs.ext4 in initrd

mkfs.ext4 in the initrd is a dynamically compiled binary that was taken from the ubuntu 16.04 distribution when we were initially testing. In the final product, we want a statically compiled mkfs.ext4 that we can verify the origin. There are two things we can investigate:

Busybox comes with mkfs.ext2. We can see if we can compile busybox to include mkfs.ext4.
Statically compile our own http://e2fsprogs.sourceforge.net/ which has ext4 support

Connecting to vsock sometimes times out

When running a process and trying to connect to stdio, we can get the following stack trace:

failed creating stdout Connection: failed connecting the VsockConnection: failed connect() to 00000002.40000081: connection timed out
      github.com/Microsoft/opengcs/service/gcs/transport.(*VsockTransport).Dial
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/transport/vsock.go:27
      github.com/Microsoft/opengcs/service/gcs/bridge.connectStdio
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/bridge/connection.go:84
      github.com/Microsoft/opengcs/service/gcs/bridge.(*bridge).runExternalProcess
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/bridge/bridge.go:323
      github.com/Microsoft/opengcs/service/gcs/bridge.(*bridge).execProcess
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/bridge/bridge.go:221
      github.com/Microsoft/opengcs/service/gcs/bridge.(*bridge).loop
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/bridge/bridge.go:88
      github.com/Microsoft/opengcs/service/gcs/bridge.(*bridge).CommandLoop
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/bridge/bridge.go:52
      main.main
        /home/serviceb/golang/src/github.com/Microsoft/opengcs/service/gcs/main.go:60
      runtime.main
        /usr/lib/go-1.6/src/runtime/proc.go:188
      runtime.goexit
        /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
      at <ScriptBlock>, C:\test\LinuxContainer.Tests.ps1: line 192

The timeout occurs in the virtsock library. If we want to be able to configure the timeout ourselves, it might make sense for virtsock to have some way of exposing sockopts, so we could set timeout there. Another potential option is just retrying on timeout in the GCS.

Cleanup calls to logrus with addtional newlines

Logrus calls shouldn't need trailing newlines.

Unnecessary files layer1, layer2, layer3, scratch in service/gcs/core/gcs

Are these files used?

VhdToTar: copyWithTimeout on the stdout pipe

Environment:

Windows Build: Windows 10 Pro Insider Build 16296
LinuxKit kernel 4.12.14
Docker master build: daemon c982ee8 client a41caad

While running some tests in a loop, I occasionally get a hang with the following error message:

DEBU[2017-09-26T16:18:34.617012400+01:00] lcowdriver: applydiff: id 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493
DEBU[2017-09-26T16:18:34.618012300+01:00] lcowdriver: startservicevmifnotrunning 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493:: Adding entry to service vm map
DEBU[2017-09-26T16:18:34.618012300+01:00] lcowdriver: startservicevmifnotrunning 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493:: service vm doesn't exist. Now starting it up: 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493
DEBU[2017-09-26T16:18:34.618012300+01:00] lcowdriver: startservicevmifnotrunning 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493: locking cachedScratchMutex
DEBU[2017-09-26T16:18:34.618012300+01:00] lcowdriver: startServiceVmIfNotRunning: (applydiff 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493) cloning cached scratch for mvd
DEBU[2017-09-26T16:18:34.635010700+01:00] lcowdriver: startServiceVmIfNotRunning: (applydiff 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493) adding cloned scratch as mvd
DEBU[2017-09-26T16:18:34.635010700+01:00] lcowdriver: startservicevmifnotrunning 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493: releasing cachedScratchMutex
DEBU[2017-09-26T16:18:34.635010700+01:00] lcowdriver: startServiceVmIfNotRunning: (applydiff 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493) starting 6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm
DEBU[2017-09-26T16:18:34.636012000+01:00] opengcs: StartUtilityVM: &{Options:{KirdPath:C:\Program Files\Linux Containers KernelFile:bootx64.efi InitrdFile:initrd.img Vhdx:C:\Program Files\Linux Containers\uvm.vhdx TimeoutSeconds:0 BootParameters:console=ttyS0} Name:6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm RequestedMode:3 ActualMode:0 UvmTimeoutSeconds:300 Uvm:<nil> MappedVirtualDisks:[{HostPath:C:\lcow\lcow\scratch\6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493.vhdx ContainerPath:/tmp/scratch CreateInUtilityVM:true ReadOnly:false Cache: AttachOnly:false}]}
DEBU[2017-09-26T16:18:34.636012000+01:00] opengcs: StartUtilityVM: calling HCS with '{"SystemType":"container","Name":"6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm","Layers":null,"HvPartition":true,"HvRuntime":{"ImagePath":"C:\\Program Files\\Linux Containers","LinuxInitrdFile":"initrd.img","LinuxKernelFile":"bootx64.efi","LinuxBootParameters":"console=ttyS0"},"ContainerType":"linux","TerminateOnLastHandleClosed":true,"MappedVirtualDisks":[{"HostPath":"C:\\lcow\\lcow\\scratch\\6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493.vhdx","ContainerPath":"/tmp/scratch","CreateInUtilityVM":true,"AttachOnly":false}]}'
DEBU[2017-09-26T16:18:34.636012000+01:00] HCSShim::CreateContainer id=6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm config={"SystemType":"container","Name":"6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm","Layers":null,"HvPartition":true,"HvRuntime":{"ImagePath":"C:\\Program Files\\Linux Containers","LinuxInitrdFile":"initrd.img","LinuxKernelFile":"bootx64.efi","LinuxBootParameters":"console=ttyS0"},"ContainerType":"linux","TerminateOnLastHandleClosed":true,"MappedVirtualDisks":[{"HostPath":"C:\\lcow\\lcow\\scratch\\6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493.vhdx","ContainerPath":"/tmp/scratch","CreateInUtilityVM":true,"AttachOnly":false}]}
DEBU[2017-09-26T16:18:34.637010100+01:00] HCSShim::CreateContainer id=6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm merged config={"ContainerType":"linux","HvPartition":true,"HvRuntime":{"Com1PipeName":"\\\\localhost\\pipe\\vmpipe","ImagePath":"C:\\Program Files\\Linux Containers","LinuxBootParameters":"console=ttyS0","LinuxInitrdFile":"initrd.img","LinuxKernelFile":"bootx64.efi"},"Layers":null,"MappedVirtualDisks":[{"AttachOnly":false,"ContainerPath":"/tmp/scratch","CreateInUtilityVM":true,"HostPath":"C:\\lcow\\lcow\\scratch\\6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493.vhdx"}],"Name":"6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm","SystemType":"container","TerminateOnLastHandleClosed":true}
ERRO[2017-09-26T16:23:34.609311500+01:00] opengcs: VhdToTar: C:\lcow\lcow\ee614ea0c685cb5613f8919adf7dd82cb7a894407926b24bb4d7cc409e406306\sandbox.vhdx:  copyWithTimeout on the stdout pipe (from utility VM) failed: opengcs: copyWithTimeout: timed out (vhdtotarstream: copy tarstream from exportSandbox -path /tmp/ee614ea0c685cb5613f8919adf7dd82cb7a894407926b24bb4d7cc409e406306)
DEBU[2017-09-26T16:23:34.609311500+01:00] opengcs: VhdToTar: copied 0 bytes of the tarstream of C:\lcow\lcow\ee614ea0c685cb5613f8919adf7dd82cb7a894407926b24bb4d7cc409e406306\sandbox.vhdx from the utility VM
DEBU[2017-09-26T16:23:34.610280300+01:00] HCSShim::Process::Close processid=463
DEBU[2017-09-26T16:23:34.610280300+01:00] HCSShim::Process::Close succeeded processid=463

and then nothing happens.

PS C:\WINDOWS\system32> hcsdiag list
6a1cda21328e8afbcfd33f97a38f4524cff2de90d305dfbc92ba2e38f74a7493_svm
    Hyper-V Linux Container,    Created

ee614ea0c685cb5613f8919adf7dd82cb7a894407926b24bb4d7cc409e406306_svm
    Hyper-V Linux Container,    Running

The test uses two files:
.\fakenpm\Dockerfile

FROM node:6-onbuild

.\fakenpm\packages.json:

{
  "name": "fakenpm",
  "version": "1.0.0",
  "description": "",
  "main": "index.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "author": "",
  "license": "ISC"
}

and then runs:

for ($i=1; $i -le 50; $i++) { docker build -t foo fakenpm; docker system prune -a -f }

vsock fds are being accidentally duped to child processes

This is preventing vsock sockets from being closed, which is blocking EOFs from making it back to the host. As a result, docker commit isn't working when in single service VM mode.

This is fixed by linuxkit/virtsock#35. We will need to vendor that in once it is merged.

Configure interface statically when PrefixLength is non-zero

This should be done even if NatEnabled is false.

nginx is not working due to missing /dev/stdout and /dev/stderr

Using master of OpenGCS (2dad06f038530dc305fb139a281507f1002e7e51) and latest master from docker (see below) running nginx fails:

PS> ./docker run nginx
nginx: [alert] could not open error log file: open() "/var/log/nginx/error.log" failed (6: No such device or address)
2017/08/16 16:59:18 [emerg] 1#1: open() "/var/log/nginx/error.log" failed (6: No such device or address)

I noticed this on earlier versions as well.

The nginx container has symlinks to /dev/stdout and /dev/stderr:

# ls -l var/log/nginx/
total 0
lrwxrwxrwx 1 root root 11 Jul 26 07:34 access.log -> /dev/stdout
lrwxrwxrwx 1 root root 11 Jul 26 07:34 error.log -> /dev/stderr

and when run as ./docker run -ti nginx on LCOW it works.

docker run nginx on Linux works and doing a runc exec in to the nginx container on Linux (well Docker for Mac actually) we see:

runc exec -t 86eb48a37c971e3912879f8415fb6362a5cdda8d0dd0fb16ecc3e9e2dc4ba070 ls -l /dev
total 0
lrwxrwxrwx 1 root root   11 Aug 16 17:26 core -> /proc/kcore
lrwxrwxrwx 1 root root   13 Aug 16 17:26 fd -> /proc/self/fd
crw-rw-rw- 1 root root 1, 7 Aug 16 17:26 full
drwxrwxrwt 2 root root   40 Aug 16 17:26 mqueue
crw-rw-rw- 1 root root 1, 3 Aug 16 17:26 null
lrwxrwxrwx 1 root root    8 Aug 16 17:26 ptmx -> pts/ptmx
drwxr-xr-x 2 root root    0 Aug 16 17:26 pts
crw-rw-rw- 1 root root 1, 8 Aug 16 17:26 random
drwxrwxrwt 2 root root   40 Aug 16 17:26 shm
lrwxrwxrwx 1 root root   15 Aug 16 17:26 stderr -> /proc/self/fd/2
lrwxrwxrwx 1 root root   15 Aug 16 17:26 stdin -> /proc/self/fd/0
lrwxrwxrwx 1 root root   15 Aug 16 17:26 stdout -> /proc/self/fd/1
crw-rw-rw- 1 root root 5, 0 Aug 16 17:26 tty
crw-rw-rw- 1 root root 1, 9 Aug 16 17:26 urandom
crw-rw-rw- 1 root root 1, 5 Aug 16 17:26 zero

So this has the device present. I suspect this might be something which opengcs has to do, but doesn't do because terminal is not set to true in the config file.

I've also attached the config.json file from executing docker run nginx on Linux

Full docker daemon logs:

DEBU[2017-08-16T18:05:32.913548500+01:00] libcontainerd: waitExit() completed OK, {CommonStateInfo:{State:exit Pid:418 ExitCode:1 ProcessID:init} UpdatePending:false}
DEBU[2017-08-16T18:05:55.168766800+01:00] Calling GET /_ping
DEBU[2017-08-16T18:05:55.170768500+01:00] Calling POST /v1.31/containers/create
DEBU[2017-08-16T18:05:55.170768500+01:00] form data: {"AttachStderr":true,"AttachStdin":false,"AttachStdout":true,"Cmd":null,"Domainname":"","Entrypoint":null,"Env":[],"HostConfig":{"AutoRemove":false,"Binds":null,"BlkioDeviceReadBps":null,"BlkioDeviceReadIOps":null,"BlkioDeviceWriteBps":null,"BlkioDeviceWriteIOps":null,"BlkioWeight":0,"BlkioWeightDevice":[],"CapAdd":null,"CapDrop":null,"Cgroup":"","CgroupParent":"","ConsoleSize":[30,125],"ContainerIDFile":"","CpuCount":0,"CpuPercent":0,"CpuPeriod":0,"CpuQuota":0,"CpuRealtimePeriod":0,"CpuRealtimeRuntime":0,"CpuShares":0,"CpusetCpus":"","CpusetMems":"","DeviceCgroupRules":null,"Devices":[],"DiskQuota":0,"Dns":[],"DnsOptions":[],"DnsSearch":[],"ExtraHosts":null,"GroupAdd":null,"IOMaximumBandwidth":0,"IOMaximumIOps":0,"IpcMode":"","Isolation":"","KernelMemory":0,"Links":null,"LogConfig":{"Config":{},"Type":""},"Memory":0,"MemoryReservation":0,"MemorySwap":0,"MemorySwappiness":-1,"NanoCpus":0,"NetworkMode":"default","OomKillDisable":false,"OomScoreAdj":0,"PidMode":"","PidsLimit":0,"PortBindings":{},"Privileged":false,"PublishAllPorts":false,"ReadonlyRootfs":false,"RestartPolicy":{"MaximumRetryCount":0,"Name":"no"},"SecurityOpt":null,"ShmSize":0,"UTSMode":"","Ulimits":null,"UsernsMode":"","VolumeDriver":"","VolumesFrom":null},"Hostname":"","Image":"nginx","Labels":{},"NetworkingConfig":{"EndpointsConfig":{}},"OnBuild":null,"OpenStdin":false,"StdinOnce":false,"Tty":false,"User":"","Volumes":{},"WorkingDir":""}
DEBU[2017-08-16T18:05:55.172803900+01:00] lcowdriver: createreadwrite: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:55.172803900+01:00] lcowdriver: create: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 parent: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b
DEBU[2017-08-16T18:05:55.172803900+01:00] lcowdriver: getlayerchain: id b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b json C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layerchain.json
DEBU[2017-08-16T18:05:55.172803900+01:00] lcowdriver: exists: id b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b true
DEBU[2017-08-16T18:05:55.173803400+01:00] lcowdriver: create: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414: creating C:\lcow\lcow\b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:55.173803400+01:00] lcowdriver: setlayerchain: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 json C:\lcow\lcow\b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414\layerchain.json
DEBU[2017-08-16T18:05:55.175769700+01:00] lcowdriver: create: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414: success
DEBU[2017-08-16T18:05:55.175769700+01:00] lcowdriver: createreadwrite: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414: locking cachedSandboxMutex
DEBU[2017-08-16T18:05:55.175769700+01:00] lcowdriver: createreadwrite: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414: releasing cachedSandboxMutex
DEBU[2017-08-16T18:05:55.175769700+01:00] lcowdriver: createreadwrite: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414: using cached sandbox to populate
DEBU[2017-08-16T18:05:55.238774600+01:00] Calling POST /v1.31/containers/b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414/attach?stderr=1&stdout=1&stream=1
DEBU[2017-08-16T18:05:55.238774600+01:00] attach: stdout: begin
DEBU[2017-08-16T18:05:55.238774600+01:00] attach: stderr: begin
DEBU[2017-08-16T18:05:55.238774600+01:00] Calling POST /v1.31/containers/b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414/wait?condition=next-exit
DEBU[2017-08-16T18:05:55.239766600+01:00] Calling POST /v1.31/containers/b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414/start
DEBU[2017-08-16T18:05:55.250766700+01:00] Assigning addresses for endpoint stoic_snyder's interface on network nat
DEBU[2017-08-16T18:05:55.250766700+01:00] RequestAddress(172.24.208.0/20, <nil>, map[])
DEBU[2017-08-16T18:05:55.250766700+01:00] [POST]=>[/endpoints/] Request : {"VirtualNetwork":"5ced68dc-b1a8-4deb-a5a5-6dc7847642d2","EnableInternalDNS":true}
DEBU[2017-08-16T18:05:55.254770400+01:00] Network Response : { "ActivityId" : "8c28fcca-6998-43bd-a71b-c336b50bae45", "CreateProcessingStartTime" : 131473767552537705, "DNSServerList" : "172.24.208.1,10.14.32.10", "DNSSuffix" : "cam.docker.com", "EnableInternalDNS" : true, "EnableLowInterfaceMetric" : true, "GatewayAddress" : "172.24.208.1", "ID" : "0aabdc45-2a7e-4782-81ec-b1cf66f830f1", "IPAddress" : "172.24.222.158", "MacAddress" : "00-15-5D-50-4C-29", "Name" : "Ethernet", "Policies" : [  ], "PrefixLength" : 20, "Resources" : { "AllocationOrder" : 0, "ID" : "8c28fcca-6998-43bd-a71b-c336b50bae45", "PortOperationTime" : 0, "State" : 1, "SwitchOperationTime" : 0, "VfpOperationTime" : 0, "parentId" : "2c9779ad-e79a-4ded-b875-088008d05ea0" }, "SharedContainers" : [  ], "State" : 1, "Type" : "nat", "Version" : 21474836481, "VirtualNetwork" : "5ced68dc-b1a8-4deb-a5a5-6dc7847642d2", "VirtualNetworkName" : "nat" }
DEBU[2017-08-16T18:05:55.271935400+01:00] Assigning addresses for endpoint stoic_snyder's interface on network nat
DEBU[2017-08-16T18:05:55.344018500+01:00] Programming external connectivity on endpoint stoic_snyder (bc6cf0df71677e68bbce73e6c1a5bd965835badd1ca0b3763a0e5be281512c8c)
DEBU[2017-08-16T18:05:55.345029500+01:00] EnableService b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 START
DEBU[2017-08-16T18:05:55.346015000+01:00] EnableService b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 DONE
DEBU[2017-08-16T18:05:55.361019800+01:00] lcowdriver: getmetadata: id b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:55.362021000+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb
DEBU[2017-08-16T18:05:55.362021000+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\layer.vhd, size 89653760, isSandbox false
DEBU[2017-08-16T18:05:55.362021000+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: locking cacheMutex
DEBU[2017-08-16T18:05:55.363021900+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: added cache item &{Mutex:{state:0 sema:0} uvmPath:/mnt/5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb hostPath:C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\layer.vhd refCount:1 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.364017600+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: releasing cacheMutex
DEBU[2017-08-16T18:05:55.369029500+01:00] lcowdriver: get: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb success. C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: &{Mutex:{state:0 sema:0} uvmPath:/mnt/5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb hostPath:C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\layer.vhd refCount:1 isSandbox:false isMounted:false}: size 89653760
DEBU[2017-08-16T18:05:55.370019700+01:00] lcowdriver: put: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: locking cacheMutex
DEBU[2017-08-16T18:05:55.370019700+01:00] locking cache item for decrement
DEBU[2017-08-16T18:05:55.371735600+01:00] decremented refcount on cache item &{Mutex:{state:1 sema:0} uvmPath:/mnt/5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb hostPath:C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\layer.vhd refCount:0 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.372128400+01:00] lcowdriver: put: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: releasing cacheMutex. Ref count on cache item has dropped to zero, removed from cache
DEBU[2017-08-16T18:05:55.373158000+01:00] lcowdriver: put: 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb: refCount 0. C:\lcow\lcow\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\layer.vhd (/mnt/5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb) completed successfully
DEBU[2017-08-16T18:05:55.375174900+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4
DEBU[2017-08-16T18:05:55.380155800+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\layer.vhd, size 63963648, isSandbox false
DEBU[2017-08-16T18:05:55.380155800+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: locking cacheMutex
DEBU[2017-08-16T18:05:55.382156900+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: added cache item &{Mutex:{state:0 sema:0} uvmPath:/mnt/acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 hostPath:C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\layer.vhd refCount:1 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.385157100+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: releasing cacheMutex
DEBU[2017-08-16T18:05:55.390752900+01:00] lcowdriver: get: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 success. C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: &{Mutex:{state:0 sema:0} uvmPath:/mnt/acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 hostPath:C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\layer.vhd refCount:1 isSandbox:false isMounted:false}: size 63963648
DEBU[2017-08-16T18:05:55.391641500+01:00] lcowdriver: put: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: locking cacheMutex
DEBU[2017-08-16T18:05:55.396506400+01:00] locking cache item for decrement
DEBU[2017-08-16T18:05:55.398535900+01:00] decremented refcount on cache item &{Mutex:{state:1 sema:0} uvmPath:/mnt/acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 hostPath:C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\layer.vhd refCount:0 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.400555100+01:00] lcowdriver: put: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: releasing cacheMutex. Ref count on cache item has dropped to zero, removed from cache
DEBU[2017-08-16T18:05:55.400555100+01:00] lcowdriver: put: acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4 acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4: refCount 0. C:\lcow\lcow\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\layer.vhd (/mnt/acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4) completed successfully
DEBU[2017-08-16T18:05:55.401517400+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b
DEBU[2017-08-16T18:05:55.402501100+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layer.vhd, size 262656, isSandbox false
DEBU[2017-08-16T18:05:55.402501100+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: locking cacheMutex
DEBU[2017-08-16T18:05:55.403504700+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: added cache item &{Mutex:{state:0 sema:0} uvmPath:/mnt/b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b hostPath:C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layer.vhd refCount:1 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.404500900+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: releasing cacheMutex
DEBU[2017-08-16T18:05:55.405500700+01:00] lcowdriver: get: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b success. C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: &{Mutex:{state:0 sema:0} uvmPath:/mnt/b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b hostPath:C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layer.vhd refCount:1 isSandbox:false isMounted:false}: size 262656
DEBU[2017-08-16T18:05:55.405500700+01:00] lcowdriver: put: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: locking cacheMutex
DEBU[2017-08-16T18:05:55.406501100+01:00] locking cache item for decrement
DEBU[2017-08-16T18:05:55.407501000+01:00] decremented refcount on cache item &{Mutex:{state:1 sema:0} uvmPath:/mnt/b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b hostPath:C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layer.vhd refCount:0 isSandbox:false isMounted:false}
DEBU[2017-08-16T18:05:55.415502800+01:00] lcowdriver: put: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: releasing cacheMutex. Ref count on cache item has dropped to zero, removed from cache
DEBU[2017-08-16T18:05:55.415502800+01:00] lcowdriver: put: b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b: refCount 0. C:\lcow\lcow\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\layer.vhd (/mnt/b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b) completed successfully
DEBU[2017-08-16T18:05:55.429884800+01:00] libcontainerd: client.Create() with spec {"ociVersion":"1.0.0-rc5-dev","platform":{"os":"linux","arch":"amd64"},"process":{"consoleSize":{"height":0,"width":0},"user":{"uid":0,"gid":0},"args":["nginx","-g","daemon off;"],"env":["PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin","HOSTNAME=b2a7cab1d2bf","NGINX_VERSION=1.13.3-1~stretch","NJS_VERSION=1.13.3.0.1.11-1~stretch"],"cwd":"/","capabilities":{"bounding":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"effective":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"inheritable":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"permitted":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"]}},"root":{"path":"rootfs"},"hostname":"b2a7cab1d2bf","mounts":[{"destination":"/proc","type":"proc","source":"proc","options":["nosuid","noexec","nodev"]},{"destination":"/dev","type":"tmpfs","source":"tmpfs","options":["nosuid","strictatime","mode=755","size=65536k"]},{"destination":"/dev/pts","type":"devpts","source":"devpts","options":["nosuid","noexec","newinstance","ptmxmode=0666","mode=0620","gid=5"]},{"destination":"/sys","type":"sysfs","source":"sysfs","options":["nosuid","noexec","nodev","ro"]},{"destination":"/sys/fs/cgroup","type":"cgroup","source":"cgroup","options":["ro","nosuid","noexec","nodev"]},{"destination":"/dev/mqueue","type":"mqueue","source":"mqueue","options":["nosuid","noexec","nodev"]},{"destination":"/dev/shm","type":"tmpfs","source":"shm","options":["nosuid","noexec","nodev","mode=1777"]}],"linux":{"resources":{"devices":[{"allow":false,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":5,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":3,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":9,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":8,"access":"rwm"},{"allow":true,"type":"c","major":5,"minor":0,"access":"rwm"},{"allow":true,"type":"c","major":5,"minor":1,"access":"rwm"},{"allow":false,"type":"c","major":10,"minor":229,"access":"rwm"}]},"namespaces":[{"type":"mount"},{"type":"network"},{"type":"uts"},{"type":"pid"},{"type":"ipc"}],"maskedPaths":["/proc/kcore","/proc/latency_stats","/proc/timer_list","/proc/timer_stats","/proc/sched_debug"],"readonlyPaths":["/proc/asound","/proc/bus","/proc/fs","/proc/irq","/proc/sys","/proc/sysrq-trigger"]}}
DEBU[2017-08-16T18:05:55.430882800+01:00] libcontainerd: createLinux(): containerId b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:55.434889300+01:00] hcsshim::NameToGuid Name b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b
DEBU[2017-08-16T18:05:55.434889300+01:00] hcsshim::NameToGuid Name acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4
DEBU[2017-08-16T18:05:55.435883100+01:00] hcsshim::NameToGuid Name 5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb
DEBU[2017-08-16T18:05:55.436884000+01:00] HCSShim::CreateContainer id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 config={"SystemType":"container","Name":"b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414","Owner":"docker","LayerFolderPath":"C:\\lcow\\lcow\\b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414","Layers":[{"ID":"ae6c0f21-6ef2-50d2-bcfb-aa6c16b7edfd","Path":"C:\\lcow\\lcow\\b9cf969e7f84d5e9d595c78b378b1742eb05b1d7def78e4e8e1a7abb3098aa2b\\layer.vhd"},{"ID":"46f8ac95-017c-59e7-91d3-91d95c272ca7","Path":"C:\\lcow\\lcow\\acc2b4eb5a9c0ae4195ea26ff851df087282f93224da3742e5810f86b16d57e4\\layer.vhd"},{"ID":"9a04ca94-160c-5caf-9551-a8e5e1ed39ae","Path":"C:\\lcow\\lcow\\5ba6fa7fb0eb1c9b38602f3e5be6125f467b666587e8b003e81ef04a662dcecb\\layer.vhd"}],"HvPartition":true,"EndpointList":["0aabdc45-2a7e-4782-81ec-b1cf66f830f1"],"HvRuntime":{"ImagePath":"C:\\Program Files\\Linux Containers","LinuxInitrdFile":"initrd.img","LinuxKernelFile":"bootx64.efi"},"AllowUnqualifiedDNSQuery":true,"ContainerType":"linux","TerminateOnLastHandleClosed":true}
DEBU[2017-08-16T18:05:56.969879200+01:00] HCSShim::CreateContainer succeeded id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 handle=74199648
DEBU[2017-08-16T18:05:56.969879200+01:00] libcontainerd: createLinux() id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414, Calling start()
DEBU[2017-08-16T18:05:56.977973800+01:00] libcontainerd: starting container  b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:56.982969600+01:00] HCSShim::Container::Start id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.014811000+01:00] HCSShim::Container::Start succeeded id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.014811000+01:00] HCSShim::Container::CreateProcess id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 config={"CommandArgs":["nginx","-g","daemon off;"],"WorkingDirectory":"/","Environment":{"HOSTNAME":"b2a7cab1d2bf","NGINX_VERSION":"1.13.3-1~stretch","NJS_VERSION":"1.13.3.0.1.11-1~stretch","PATH":"/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"},"CreateStdInPipe":true,"CreateStdOutPipe":true,"CreateStdErrPipe":true,"ConsoleSize":[0,0],"OCISpecification":{"ociVersion":"1.0.0-rc5-dev","platform":{"os":"linux","arch":"amd64"},"process":{"consoleSize":{"height":0,"width":0},"user":{"uid":0,"gid":0},"args":["nginx","-g","daemon off;"],"env":["PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin","HOSTNAME=b2a7cab1d2bf","NGINX_VERSION=1.13.3-1~stretch","NJS_VERSION=1.13.3.0.1.11-1~stretch"],"cwd":"/","capabilities":{"bounding":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"effective":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"inheritable":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"],"permitted":["CAP_CHOWN","CAP_DAC_OVERRIDE","CAP_FSETID","CAP_FOWNER","CAP_MKNOD","CAP_NET_RAW","CAP_SETGID","CAP_SETUID","CAP_SETFCAP","CAP_SETPCAP","CAP_NET_BIND_SERVICE","CAP_SYS_CHROOT","CAP_KILL","CAP_AUDIT_WRITE"]}},"root":{"path":"rootfs"},"hostname":"b2a7cab1d2bf","mounts":[{"destination":"/proc","type":"proc","source":"proc","options":["nosuid","noexec","nodev"]},{"destination":"/dev","type":"tmpfs","source":"tmpfs","options":["nosuid","strictatime","mode=755","size=65536k"]},{"destination":"/dev/pts","type":"devpts","source":"devpts","options":["nosuid","noexec","newinstance","ptmxmode=0666","mode=0620","gid=5"]},{"destination":"/sys","type":"sysfs","source":"sysfs","options":["nosuid","noexec","nodev","ro"]},{"destination":"/sys/fs/cgroup","type":"cgroup","source":"cgroup","options":["ro","nosuid","noexec","nodev"]},{"destination":"/dev/mqueue","type":"mqueue","source":"mqueue","options":["nosuid","noexec","nodev"]},{"destination":"/dev/shm","type":"tmpfs","source":"shm","options":["nosuid","noexec","nodev","mode=1777"]}],"linux":{"resources":{"devices":[{"allow":false,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":5,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":3,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":9,"access":"rwm"},{"allow":true,"type":"c","major":1,"minor":8,"access":"rwm"},{"allow":true,"type":"c","major":5,"minor":0,"access":"rwm"},{"allow":true,"type":"c","major":5,"minor":1,"access":"rwm"},{"allow":false,"type":"c","major":10,"minor":229,"access":"rwm"}]},"namespaces":[{"type":"mount"},{"type":"network"},{"type":"uts"},{"type":"pid"},{"type":"ipc"}],"maskedPaths":["/proc/kcore","/proc/latency_stats","/proc/timer_list","/proc/timer_stats","/proc/sched_debug"],"readonlyPaths":["/proc/asound","/proc/bus","/proc/fs","/proc/irq","/proc/sys","/proc/sysrq-trigger"]}}}
DEBU[2017-08-16T18:05:57.174935400+01:00] HCSShim::Container::CreateProcess succeeded id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 processid=419
DEBU[2017-08-16T18:05:57.174935400+01:00] HCSShim::Process::Stdio processid=419
DEBU[2017-08-16T18:05:57.175935800+01:00] HCSShim::Process::Stdio succeeded processid=419
DEBU[2017-08-16T18:05:57.176942600+01:00] libcontainerd: process started - PID 419
DEBU[2017-08-16T18:05:57.183953900+01:00] libcontainerd: waitExit() on pid 419
DEBU[2017-08-16T18:05:57.183953900+01:00] HCSShim::Process::Wait processid=419
DEBU[2017-08-16T18:05:57.183953900+01:00] HCSShim::Process::CloseStdin processid=419
DEBU[2017-08-16T18:05:57.194935900+01:00] HCSShim::Process::CloseStdin succeeded processid=419
DEBU[2017-08-16T18:05:57.194935900+01:00] libcontainerd: start() completed OK, {CommonStateInfo:{State:start-container Pid:419 ExitCode:0 ProcessID:} UpdatePending:false}
DEBU[2017-08-16T18:05:57.216937100+01:00] libcontainerd: createLinux() id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414 completed successfully
DEBU[2017-08-16T18:05:57.651837900+01:00] HCSShim::Process::Wait succeeded processid=419
DEBU[2017-08-16T18:05:57.652837800+01:00] HCSShim::Process::ExitCode processid=419
DEBU[2017-08-16T18:05:57.655953400+01:00] HCSShim::Process::properties processid=419
DEBU[2017-08-16T18:05:57.658837100+01:00] HCSShim::Process::properties succeeded processid=419, properties={"ProcessId":419,"Exited":true,"ExitCode":1,"LastWaitResult":0}
DEBU[2017-08-16T18:05:57.658837100+01:00] HCSShim::Process::ExitCode succeeded processid=419 exitCode=1
DEBU[2017-08-16T18:05:57.660840100+01:00] libcontainerd: shutting down container b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.661922500+01:00] HCSShim::Container::Shutdown id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.662851000+01:00] HCSShim::Container::WaitTimeout id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.729938800+01:00] HCSShim::Container::WaitTimeout succeeded id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.730931300+01:00] libcontainerd: completed shutting down container b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.731944600+01:00] HCSShim::Container::Close id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.735103800+01:00] HCSShim::Container::Close succeeded id=b2a7cab1d2bf34243ae9c753df72a2b12dd39c1d85e66873d58d38de385e2414
DEBU[2017-08-16T18:05:57.736113900+01:00] HCSShim::Process::Close processid=419
DEBU[2017-08-16T18:05:57.737126300+01:00] HCSShim::Process::Close succeeded processid=419
DEBU[2017-08-16T18:05:57.738136900+01:00] libcontainerd: waitExit() calling backend.StateChanged {CommonStateInfo:{State:exit Pid:419 ExitCode:1 ProcessID:init} UpdatePending:false}
DEBU[2017-08-16T18:05:57.740137600+01:00] attach: stdout: end
DEBU[2017-08-16T18:05:57.740137600+01:00] attach: stderr: end
DEBU[2017-08-16T18:05:57.754139700+01:00] Revoking external connectivity on endpoint stoic_snyder (bc6cf0df71677e68bbce73e6c1a5bd965835badd1ca0b3763a0e5be281512c8c)
DEBU[2017-08-16T18:05:57.789266900+01:00] [DELETE]=>[/endpoints/0aabdc45-2a7e-4782-81ec-b1cf66f830f1] Request :
DEBU[2017-08-16T18:05:57.812786900+01:00] Releasing addresses for endpoint stoic_snyder's interface on network nat
DEBU[2017-08-16T18:05:57.813759900+01:00] ReleaseAddress(172.24.208.0/20, 172.24.222.158)
DEBU[2017-08-16T18:05:57.873252100+01:00] libcontainerd: waitExit() completed OK, {CommonStateInfo:{State:exit Pid:419 ExitCode:1 ProcessID:init} UpdatePending:false}

Docker version:

Client:
 Version:      17.06.0-dev
 API version:  1.31
 Go version:   go1.8.3
 Git commit:   35c60bb
 Built:        Tue Aug 15 23:36:42 2017
 OS/Arch:      windows/amd64

Server:
 Version:      17.06.0-dev
 API version:  1.32 (minimum version 1.24)
 Go version:   go1.8.3
 Git commit:   cd90284
 Built:        Tue Aug 15 23:40:33 2017
 OS/Arch:      windows/amd64
 Experimental: false

nginx-linux.config.json.txt

Test Bridge error paths

At the moment, the bridge's error paths are not being tested. They should.

Permission on root filesystem prevent non-root users

Only root has access to /:

./docker run --rm busybox ls -al /
total 44
drwx------    1 root     root          4096 Jul 19 10:00 .
drwx------    1 root     root          4096 Jul 19 10:00 ..
drwxr-xr-x    2 root     root         12288 Jun 15 00:40 bin
[...]

while on Linux:

docker run busybox ls -al /
total 44
drwxr-xr-x    1 root     root          4096 Jul 19 10:03 .
drwxr-xr-x    1 root     root          4096 Jul 19 10:03 ..
drwxr-xr-x    2 root     root         12288 Jul 18 19:40 bin
[...]

This prevents containers with non-root users to run

Update vendored dependencies

Look at which of our dependencies are out of date (i.e. docker, containerd, runc) and update them appropriately.

Is the init file actually correct?

https://github.com/Microsoft/opengcs/blob/master/kernelconfig/4.11/scripts/init_script#L24-L25

Why not just run gcs in the foreground at this point. Then you don't need a shell....

@gupta-ak @soccerGB @beweedon

Network config is not transferred into container

I added some additional logging to the networking code
0001-Add-logging-to-the-networking-code.patch.txt to debug some networking issue we were seeing.

The log when running docker.exe run --rm -ti busybox /bin/sh in one window and then hcsdiag.exe read -uvm <id> /tmp/gcs.log in another window shows after the interface was configured in the root namespace

time="2017-07-15T12:20:02Z" level=info msg="/go/src/github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus/entry.go:96 github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus.Entry.log() Configure network adapter 74d16c5a-de09-42f1-ba7a-26b29aed3c13[eth0]: 172.29.14.129/%!s(uint8=20) metric=1 hostip=172.29.0.1, DNSServers=172.29.0.1,10.0.1.1." 
time="2017-07-15T12:20:02Z" level=info msg="/go/src/github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus/entry.go:96 github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus.Entry.log() ifconfig eth0:
eth0      Link encap:Ethernet  HWaddr 00:15:5D:2F:67:C3  
          inet addr:172.29.14.129  Bcast:0.0.0.0  Mask:255.255.240.0
          inet6 addr: fe80::215:5dff:fe2f:67c3/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

and before it is moved to the new network namespace:

time="2017-07-15T12:20:03Z" level=info msg="/go/src/github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus/entry.go:96 github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus.Entry.log() Move network adapter 74d16c5a-de09-42f1-ba7a-26b29aed3c13[eth0] into namespace 383" 
time="2017-07-15T12:20:03Z" level=info msg="/go/src/github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus/entry.go:96 github.com/Microsoft/opengcs/vendor/github.com/Sirupsen/logrus.Entry.log() ifconfig eth0:
eth0      Link encap:Ethernet  HWaddr 00:15:5D:2F:67:C3  
          inet addr:172.29.14.129  Bcast:0.0.0.0  Mask:255.255.240.0
          inet6 addr: fe80::215:5dff:fe2f:67c3/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:2 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:176 (176.0 B)

So at this point, everything looks ok. However in the container:

/ # ifconfig
lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

tunl0     Link encap:UNSPEC  HWaddr 00-00-00-00-30-30-30-30-00-00-00-00-00-00-00-00
          UP RUNNING NOARP  MTU:1480  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

The interface is not configured.

Looking at the code in https://github.com/Microsoft/opengcs/blob/master/service/gcs/core/gcs/networking.go#L178, I don't think it is save as Go gives very little control over which OS threads code runs, while the namespace setting is tied to the namespace. See, for example, this article for more details.

I've tried to runtime.LockOSThread() at the start of moveAdapterIntoNamespace() to no avail. I suspect that by the time that code gets executed there are already a number of threads and go routines running inside the process so this doesn't help.

It's probably safer to start a dedicated helper process to move the interface over to the new namespace. Alternatively, if the network interface is not needed in the root namespace, it would be simpler to just perform the network configuration (ie configureNetworkAdapter()) inside the new namespace instead of moving the config.

Full log:
gcs.log.txt

Do we need to keep state for mapped disks and directories?

Since the GCS assumes the HCS is trusted and keeps its own state about mapped disks and directories, such as their ContainerPaths, does the GCS need to keep any state about which disks and directories are currently mounted into the UVM?

Add Console Resize support

GCS not always returning exit code for a process

@jhowardmsft - Logging for ya.

Running a command like:
docker run --rm ubuntu bash exit 123

Will return in an exit code from the HCS of 0.

Document the GCS protocol better

This could include better documentation in protocol.go as well as external documentation.

Better error and panic recovery in GCS

On a panic or on an error, the GCS shouldn't crash, exit, or otherwise stop responding. It should do a better job of recovering from errors like this.

docker doesn't use gid/uid

docker run memcached complains that it cannot run as root user without the -u flag. It looks like the uid + gid aren't being filled in the OCI spec.

Check file permissions throughout GCS code

Sometimes the GCS opens a file or sets the permissions on a file. We should check to make sure the permissions being used in each instance are what we want, and change them if not.

Rename errors package to gcserr

busybox make menuconfig can trim up a lot of un-needed fat

Needs some investigation. There's a bunch of stuff we don't actually need. We can save the config in this repo for rebuilding.

Move runc logs to per-container directory

Currently, we have global runc logs for the entire utility VM at /var/run/gcsrunc/log.log. We should probably move logs to /tmp/gcs/<containerID>/runc.log, so it will be in the same directory as gcs.log. This should be a pretty simple change to the runc wrapper code.

Potentially support per-adapter DNS

The HCS specifies DNS configuration on a per-adapter, rather than per-container, basis. This could maybe be supported with something like dnsmasq.

docker doesn't use memory or CPU options

For example, if I try running mssql-server-linux image with -m=4g, I get this error sqlservr: This program requires a machine with at least 3250 megabytes of memory.

Implement new Protocol Negotiation

Is this a multicontainer utility VM? We'll need to determine this in order to properly handle bridge messages, resources, etc.

GCS will delete contents of mapped directories on exit if they are under /tmp/gcs/<containerID>/

This is because the GCS apparently doesn't unmount mapped directories during cleanup (see https://github.com/Microsoft/opengcs/blob/master/service/gcs/core/gcs/cleanup.go). We should add code to perform this unmounting during the cleanup phase.

@jterry75 @jhowardmsft

Kernel patches need a Signed-off-by (DCO) line

https://github.com/Microsoft/opengcs/blob/master/kernelconfig/4.11/patch_9pfs_vsock-transport.patch and https://github.com/Microsoft/opengcs/blob/master/kernelconfig/4.11/patch_lower-the-minimum-PMEM-size.patch as well as commits 29e6c6204845176c78c7840377a72389d188563c from https://github.com/dcui/linux.git do not have the the required Signed-off-by messages in the commit. Without we (Docker/LinuxKit) can't incorporate them into our kernel.

Docker is not able to build images which has FROM scratch reference

Any docker file which has FROM scratch statement is failing at add command.
For ex:
Take docker file as below to build amazon Linux image
FROM scratch
ADD amzn-container-minimal-2017.09.0.20170930-x86_64.tar.xz /
CMD ["/bin/bash"]

The add command is failing with error:
ADD amzn-container-minimal-2017.09.0.20170930-x86_64.tar.xz /
docker : failed to copy files: svm.runProcess: command mount -t overlay
overlay -olowerdir=,upperdir=/tmp/a3ddcb18a8db585c0472bf7512e36e0dce38c65d1d414
4f893bd6ed7baef4aaf/upper,workdir=/tmp/a3ddcb18a8db585c0472bf7512e36e0dce38c65d
1d4144f893bd6ed7baef4aaf/work
/tmp/a3ddcb18a8db585c0472bf7512e36e0dce38c65d1d4144f893bd6ed7baef4aaf-mount
failed with exit code 255