Hello!
Just my observations/thoughts/ideas here, I might be wrong and don’t have access to further source code under this closed beta Docker program.
I think I found the culprit: the container dies mid-execution and so does the associated Volume(s):
2016-04-26 13:35:03,106 Docker[50370]: eventCallback container die: bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (#watchers: 1)
2016-04-26 13:35:03,106 com.docker.osxfs[50367]: Volume.stop bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam.bai, /Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam])
2016-04-26 13:35:04,021 Docker[50370]: eventCallback container start: a65cbc67ac66a341424ec8739b772a71c13d90b97d60260c56e5e210a49b6003 (#watchers: 0)
2016-04-26 13:35:10,875 Docker[50370]: eventCallback container die: a65cbc67ac66a341424ec8739b772a71c13d90b97d60260c56e5e210a49b6003 (#watchers: 1)
Earlier, it seems that the “com.docker.drive” (Storage/osxfs layer?) has some trouble keeping up with IO perhaps?:
2016-04-26 13:21:00,000 kernel[0]: process com.docker.drive[50373] caught causing excessive wakeups. Observed wakeups rate (per sec): 1010; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 117223
There’s also a stacktrace in the logs:
Powerstats for: com.docker.drive [50373]
Start time: 2016-04-26 13:20:41 +0200
End time: 2016-04-26 13:20:56 +0200
Parent: com.docker.drive
Responsible: Docker
Microstackshots: 11 samples (23%)
Primary state: 9 samples Non-Frontmost App, Kernel mode, Thread QoS Legacy
User Activity: 0 samples Idle, 11 samples Active
Power Source: 0 samples on Battery, 11 samples on AC
10 thread_start + 13 (libsystem_pthread.dylib) [0x7fff9a04f3ed]
10 _pthread_start + 176 (libsystem_pthread.dylib) [0x7fff9a051fd7]
10 _pthread_body + 131 (libsystem_pthread.dylib) [0x7fff9a05205a]
8 vcpu_add + 647 (com.docker.driver.amd64-linux) [0x43e4fd7]
8 xh_vm_run + 57 (com.docker.driver.amd64-linux) [0x43da879]
6 vm_run + 523 (com.docker.driver.amd64-linux) [0x43d8a9b]
6 vmx_fix_cr4 + 2129 (com.docker.driver.amd64-linux) [0x43e0471]
6 hv_vcpu_run + 16 (Hypervisor) [0x4a760a9]
1 vm_run + 1670 (com.docker.driver.amd64-linux) [0x43d8f16]
1 vmm_fetch_instruction + 102 (com.docker.driver.amd64-linux) [0x43de446]
1 vm_copy_setup + 249 (com.docker.driver.amd64-linux) [0x43d9fc9]
1 <User mode>
1 vm_run + 1046 (com.docker.driver.amd64-linux) [0x43d8ca6]
1 __psynch_cvwait + 10 (libsystem_kernel.dylib) [0x7fff941d9136]
1 lpc_pirq_routed + 13107 (com.docker.driver.amd64-linux) [0x43c7503]
1 <User mode>
1 callout_system_init + 376 (com.docker.driver.amd64-linux) [0x43dc0b8]
1 vlapic_icrtmr_write_handler + 364 (com.docker.driver.amd64-linux) [0x43d5c1c]
1 vlapic_lvt_write_handler + 686 (com.docker.driver.amd64-linux) [0x43d598e]
1 vcpu_notify_event + 89 (com.docker.driver.amd64-linux) [0x43d87c9]
1 __psynch_cvsignal + 10 (libsystem_kernel.dylib) [0x7fff941d911e]
1 .L1166 + 19 (mirage-block.so) [0x4acc847]
1 lwt_unix_recv_notifications + 40 (mirage-block.so) [0x4b5d558]
1 __pthread_sigmask + 10 (libsystem_kernel.dylib) [0x7fff941d92b6]
Binary Images:
0x4000000 - 0x4801ff3 com.docker.driver.amd64-linux (0) <CDE0FB10-3C88-33F4-8127-2D61845AAC90> /Applications/Docker.app/Contents/MacOS/com.docker.driver.amd64-linux
0x4a75000 - 0x4a79fff com.apple.Hypervisor 1.0 (1) <7960B1D3-1EC1-379D-8CF4-F478BA67CD31> /System/Library/Frameworks/Hypervisor.framework/Versions/A/Hypervisor
0x4a87000 - 0x4bcdfff mirage-block.so (0) <00D4FC77-75C5-388B-82E3-A1D1FB72A14A> /Applications/Docker.app/Contents/Resources/lib/mirage-block.so
0x7fff941c3000 - 0x7fff941e0fff libsystem_kernel.dylib (2782.50.2) <FAA95C7E-5A59-35FD-9ED5-80BFB27BF3C7> /usr/lib/system/libsystem_kernel.dylib
0x7fff9a04e000 - 0x7fff9a057fff libsystem_pthread.dylib (105.40.1) <ACE90967-ECD0-3251-AEEB-461E3C6414F7> /usr/lib/system/libsystem_pthread.dylib
After that, docker tries to bring up those containers and Volumes repeatedly when they die:
2016-04-26 13:34:28,197 com.docker.osxfs[50367]: Volume.start 590e3cfb796d28342da5aebe3ab4ba4c5ff295b8013414777adb96dac7c44920 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.dict, /Users/romanvg/tmp/test_bcbio_cwl/testdata/automated/variant_regions-bam.bed, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa.fai])
2016-04-26 13:34:28,613 Docker[50370]: eventCallback container start: 590e3cfb796d28342da5aebe3ab4ba4c5ff295b8013414777adb96dac7c44920 (#watchers: 0)
2016-04-26 13:34:41,965 Docker[50370]: eventCallback container die: 590e3cfb796d28342da5aebe3ab4ba4c5ff295b8013414777adb96dac7c44920 (#watchers: 1)
2016-04-26 13:34:41,966 com.docker.osxfs[50367]: Volume.stop 590e3cfb796d28342da5aebe3ab4ba4c5ff295b8013414777adb96dac7c44920 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.dict, /Users/romanvg/tmp/test_bcbio_cwl/testdata/automated/variant_regions-bam.bed, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa.fai])
2016-04-26 13:34:43,029 com.docker.osxfs[50367]: Volume.start e0faa0b18377c86e6f4e7b88a8366f2c5b8700d0dfae462522ea7ef1b9c8cf75 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.dict, /Users/romanvg/tmp/test_bcbio_cwl/testdata/automated/variant_regions-bam.bed, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa.fai])
2016-04-26 13:34:43,314 Docker[50370]: eventCallback container start: e0faa0b18377c86e6f4e7b88a8366f2c5b8700d0dfae462522ea7ef1b9c8cf75 (#watchers: 0)
2016-04-26 13:34:51,967 Docker[50370]: eventCallback container die: e0faa0b18377c86e6f4e7b88a8366f2c5b8700d0dfae462522ea7ef1b9c8cf75 (#watchers: 1)
2016-04-26 13:34:51,967 com.docker.osxfs[50367]: Volume.stop e0faa0b18377c86e6f4e7b88a8366f2c5b8700d0dfae462522ea7ef1b9c8cf75 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.dict, /Users/romanvg/tmp/test_bcbio_cwl/testdata/automated/variant_regions-bam.bed, /Users/romanvg/tmp/test_bcbio_cwl/testdata/genomes/hg19/seq/hg19.fa.fai])
2016-04-26 13:34:52,548 com.docker.osxfs[50367]: Volume.start bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam.bai, /Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam])
2016-04-26 13:34:52,781 Docker[50370]: eventCallback container start: bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (#watchers: 0)
2016-04-26 13:35:03,106 Docker[50370]: eventCallback container die: bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (#watchers: 1)
2016-04-26 13:35:03,106 com.docker.osxfs[50367]: Volume.stop bf92eda7f8f08e6f216fcdf2e8814d7620ff9bc4c5de2a37c20e4200202c0a39 (paths = [/Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam.bai, /Users/romanvg/tmp/test_bcbio_cwl/testdata/100326_FC6107FAAXX/7_100326_FC6107FAAXX.bam])
2016-04-26 13:35:04,021 Docker[50370]: eventCallback container start: a65cbc67ac66a341424ec8739b772a71c13d90b97d60260c56e5e210a49b6003 (#watchers: 0)
2016-04-26 13:35:10,875 Docker[50370]: eventCallback container die: a65cbc67ac66a341424ec8739b772a71c13d90b97d60260c56e5e210a49b6003 (#watchers: 1)
So, still some rought edges to polish, but good job anyhow I love to be able to run Docker right away without all the VirtualBox/boot2docker/eval docker-machine cruft.