Docker Community Forums

Share and learn in the Docker community.

Docker crash during heavy CPU workload with NZBGet


(Muxponder) #1

Expected behavior

Application to complete; NZBGet download

Actual behavior

Application crash; during repair and construct of downloaded pieces

Information

Docker for Mac: version: mac-v1.12.0-beta18-3-gec40b14
OS X: version 10.11.5 (build: 15F34)
logs: /tmp/20160709-162606.tar.gz
[OK] docker-cli
[OK] app
[OK] menubar
[OK] virtualization
[OK] system
[OK] osxfs
[OK] db
[OK] slirp
[OK] moby-console
[OK] logs
[OK] vmnetd
[OK] env
[OK] moby
[OK] driver.amd64-linux

Diagnostic ID: F485A00A-B667-4C68-B5FE-F6768DAF0BFB

OS X: version 10.11.5 (build: 15F34)

System Diagnostic output from OS X:

Command: com.docker.hyperkit
Path: /Applications/Docker.app/Contents/MacOS/com.docker.hyperkit
Parent: com.docker.driver.amd64-linux [87190]
Responsible: Docker [87165]
Powerstats for: com.docker.hyper [87193]
Parent: com.docker.drive
Responsible: Docker
55 vcpu_thread + 1215 (com.docker.hyperkit) [0x10acf475b]
46 xh_vm_run + 663 (com.docker.hyperkit) [0x10acd3374]
42 vmx_run + 354 (com.docker.hyperkit) [0x10acd4ffd]
2 vmx_run + 3947 (com.docker.hyperkit) [0x10acd5e06]
2 vlapic_update_ppr + 96 (com.docker.hyperkit) [0x10acdbeb1]
1 vmx_run + 291 (com.docker.hyperkit) [0x10acd4fbe]
1 vmx_run + 375 (com.docker.hyperkit) [0x10acd5012]
5 xh_vm_run + 1600 (com.docker.hyperkit) [0x10acd371d]
2 xh_vm_run + 4523 (com.docker.hyperkit) [0x10acd4288]
2 vmm_emulate_instruction + 3381 (com.docker.hyperkit) [0x10acd13b1]
2 vlapic_write + 351 (com.docker.hyperkit) [0x10acdb5b4]
2 vlapic_icrtmr_write_handler + 301 (com.docker.hyperkit) [0x10acda919]
1 xh_vm_run + 843 (com.docker.hyperkit) [0x10acd3428]
1 xh_vm_run + 682 (com.docker.hyperkit) [0x10acd3387]
1 vcpu_require_state + 15 (com.docker.hyperkit) [0x10acd026a]
6 callout_thread_func + 195 (com.docker.hyperkit) [0x10acd2cfd]
1 worker_loop + 50 (com.docker.hyperkit) [0x10adce1f2]
1 execute_job + 55 (com.docker.hyperkit) [0x10adcee27]
1 pci_vtsock_rx_thread + 2327 (com.docker.hyperkit) [0x10aced58b]
1 vlapic_deliver_intr + 189 (com.docker.hyperkit) [0x10acdbb16]
1 vcpu_notify_event + 98 (com.docker.hyperkit) [0x10accfccc]
1 vcpu_thread + 1192 (com.docker.hyperkit) [0x10acf4744]
1 vmexit_inout + 311 (com.docker.hyperkit) [0x10acf4bf8]
1 pci_emul_io_handler + 115 (com.docker.hyperkit) [0x10ace5971]
1 vi_pci_write + 919 (com.docker.hyperkit) [0x10acf64e3]
1 .L415 + 28 (com.docker.hyperkit) [0x10ad36370]
0x10accf000 - 0x10ae46fff com.docker.hyperkit (0) <274E5585-B27C-334E-AE92-F3DF750039BD> /Applications/Docker.app/Contents/MacOS/com.docker.hyperkit
Powerstats for: Docker
21 TFZFC6Docker7Backend27listenForDockerStateChangesFT_T_U_FT_T + 1473 (Docker) [0x10a7b9d51]
21 TTSf4gs_d___TZFC6Docker7Backend15sendRequestSyncfSST5errorGSqOS0_5Error_4respSS + 800 (Docker) [0x10a7b5610]
0x10a76b000 - 0x10a80eff7 com.docker.docker 1.12.0-rc3-beta18 (9996) /Applications/Docker.app/Contents/MacOS/Docker

Output from ‘All System Messages’ filtering on ‘docker’

Had to remove some entries to fit…

7/9/16 4:18:26.243 PM Docker[87165]: Application version: 1.12.0-rc3-beta18 (9996)
7/9/16 4:18:26.279 PM Docker[87165]: OSX Version: Version 10.11.5 (Build 15F34)
7/9/16 4:18:26.501 PM Docker[87165]: migrator: start migration process
7/9/16 4:18:26.507 PM Docker[87165]: migrator: previous install detected
7/9/16 4:18:26.507 PM Docker[87165]: migrator: previous version is 1.12.0-rc3-beta18
7/9/16 4:18:26.507 PM Docker[87165]: migrator: no migration needed, you are good to go!
7/9/16 4:18:26.507 PM Docker[87165]: migrator: end of migration process
7/9/16 4:18:26.532 PM Docker[87165]: event tracker initialized
7/9/16 4:18:26.541 PM Docker[87165]: Bundle path: /Applications/Docker.app
7/9/16 4:18:26.543 PM Docker[87176]: Client reports version 1, commit ec40b14c72adc0bff3b01fa8886dae7f2eee1541
7/9/16 4:18:26.544 PM Docker[87165]: com.docker.docker commit: ec40b14c72adc0bff3b01fa8886dae7f2eee1541 wants version 16
7/9/16 4:18:26.544 PM Docker[87165]: com.docker.vmnetd commit: 5cbabb0783b6d281b8f579cb9f4dff38373b2c10 has version 16
7/9/16 4:18:26.544 PM Docker[87165]: probe of /var/tmp/com.docker.vmnetd.socket successful: not reinstalling component
7/9/16 4:18:26.544 PM Docker[87176]: EOF reading packet from Unix domain socket: closing
7/9/16 4:18:26.545 PM Docker[87176]: Failed to read command from client
7/9/16 4:18:26.546 PM Docker[87177]: Client reports version 1, commit ec40b14c72adc0bff3b01fa8886dae7f2eee1541
7/9/16 4:18:26.547 PM Docker[87177]: client with uid 501 requests com.docker.vmnetd install symlinks
7/9/16 4:18:26.549 PM Docker[87177]: File /usr/local/bin/docker is a symlink
7/9/16 4:18:26.552 PM Docker[87177]: File /var/run/docker.sock is a symlink or a socket
7/9/16 4:18:26.552 PM Docker[87177]: File /usr/local/bin/docker-compose is a symlink
7/9/16 4:18:26.554 PM Docker[87177]: File /var/run/docker.sock is a symlink or a socket
7/9/16 4:18:26.555 PM Docker[87177]: File /usr/local/bin/notary is a symlink
7/9/16 4:18:26.556 PM Docker[87177]: File /var/run/docker.sock is a symlink or a socket
7/9/16 4:18:26.557 PM Docker[87177]: File /usr/local/bin/docker-machine is a symlink
7/9/16 4:18:26.558 PM Docker[87177]: File /var/run/docker.sock is a symlink or a socket
7/9/16 4:18:26.559 PM Docker[87165]: Symlinks are valid.
7/9/16 4:18:26.590 PM Docker[87165]: com.docker.osx.hyperkit.linux launched with PID 87178
7/9/16 4:18:26.614 PM Docker[87179]: dial unix /Users/rb/Library/Containers/com.docker.docker/Data/s20: connect: connection refused
7/9/16 4:18:26.684 PM Docker[87178]: Acquired task manager lock
7/9/16 4:18:26.693 PM Docker[87165]: frontend process failed
7/9/16 4:18:26.699 PM Docker[87178]: Starting com.docker.db, com.docker.osxfs, com.docker.slirp, com.docker.osx.hyperkit.linux, com.docker.driver.amd64-linux
7/9/16 4:18:26.713 PM Docker[87178]: Start com.docker.db (pid 87185)
7/9/16 4:18:26.726 PM Docker[87178]: Start com.docker.osxfs (pid 87187)
7/9/16 4:18:26.747 PM Docker[87178]: Start com.docker.slirp (pid 87188)
7/9/16 4:18:26.753 PM Docker[87178]: Start com.docker.osx.hyperkit.linux (pid 87189)
7/9/16 4:18:26.769 PM Docker[87189]: API server starting
7/9/16 4:18:26.770 PM Docker[87178]: Start com.docker.driver.amd64-linux (pid 87190)
7/9/16 4:18:26.772 PM Docker[87189]: :four_leaf_clover: socket path is: /Users/rb/Library/Containers/com.docker.docker/Data/s20
7/9/16 4:18:26.773 PM Docker[87189]: API socket removed
7/9/16 4:18:26.775 PM Docker[87189]: Try 0/100 failed to connect to db: dial unix /Users/rb/Library/Containers/com.docker.docker/Data/s40: connect: connection refused
7/9/16 4:18:26.819 PM Docker[87187]: Logging to Apple System Log
7/9/16 4:18:26.868 PM Docker[87188]: Logging to Apple System Log
7/9/16 4:18:26.868 PM Docker[87188]: Setting handler to ignore all SIGPIPE signals
7/9/16 4:18:26.868 PM Docker[87188]: Setting soft fd limit to 10240
7/9/16 4:18:26.868 PM Docker[87188]: starting port_forwarding port_control_path:fd:4 vsock_path:/Users/rb/Library/Containers/com.docker.docker/Data/@connect
7/9/16 4:18:26.869 PM Docker[87188]: attempting to reconnect to database
7/9/16 4:18:26.871 PM Docker[87188]: reconnected transport layer
7/9/16 4:18:26.873 PM Docker[87188]: allowing binds to any IP addresses
7/9/16 4:18:26.875 PM Docker[87188]: Creating slirp server pcap_settings:disabled peer_ip:192.168.65.2 local_ip:192.168.65.1
7/9/16 4:18:26.887 PM Docker[87189]: VM shutdown at 2016-07-09 16:18:24 -0400 EDT
7/9/16 4:18:26.914 PM Docker[87190]: Acquired hypervisor lock
7/9/16 4:18:26.930 PM Docker[87190]: Docker is not responding: Get http://./info: dial unix /Users/rb/Library/Containers/com.docker.docker/Data/*00000003.00000948: connect: connection refused: waiting 0.5s
7/9/16 4:18:27.012 PM Docker[87190]: hypervisor: native
7/9/16 4:18:27.012 PM Docker[87190]: filesystem: osxfs
7/9/16 4:18:27.012 PM Docker[87190]: network: hybrid
7/9/16 4:18:27.014 PM Docker[87187]: Using protocol TwoThousand msize 16384
7/9/16 4:18:27.017 PM Docker[87190]: Hypervisor: native; BootProtocol: direct; UefiBootDisk: /Users/rb/UefiBoot.qcow2
7/9/16 4:18:27.017 PM Docker[87190]: Launching: /Applications/Docker.app/Contents/MacOS/com.docker.hyperkit -A -m 2G -c 2 -u -s 0:0,hostbridge -s 31,lpc -s 2:0,virtio-vpnkit,uuid=16d3ffc8-26af-432c-89c2-c39742559d63,path=/Users/rb/Library/Containers/com.docker.docker/Data/s50,macfile=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/mac.0 -s 3,virtio-blk,file:///Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2,format=qcow -s 4,virtio-9p,path=/Users/rb/Library/Containers/com.docker.docker/Data/s40,tag=db -s 5,virtio-rnd -s 6,virtio-9p,path=/Users/rb/Library/Containers/com.docker.docker/Data/s51,tag=port -s 7,virtio-sock,guest_cid=3,path=/Users/rb/Library/Containers/com.docker.docker/Data,guest_forwards=2376;1525 -l com1,autopty=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty,log=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/console-ring -f kexec,/Applications/Docker.app/Contents/Resources/moby/vmlinuz64,/Applications/Docker.app/Contents/Resources/moby/initrd.img,earlyprintk=serial console=ttyS0 com.docker.driverDir="/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux", com.docker.database=“com.docker.driver.amd64-linux” ntp=gateway -F /Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/hypervisor.pid
7/9/16 4:18:27.079 PM Docker[87188]: PPP.negotiate: received ((magic VMN3T)(version 1)(commit ec40b14c72adc0bff3b01fa8886dae7f2eee1541))
7/9/16 4:18:27.079 PM Docker[87188]: PPP.negotiate: received (Ethernet 16d3ffc8-26af-432c-89c2-c39742559d63)
7/9/16 4:18:27.079 PM Docker[87188]: PPP.negotiate: sending ((mtu 1500)(max_packet_size 1550)(client_macaddr c0:ff:ee:c0:ff:ee))
7/9/16 4:18:27.079 PM Docker[87188]: PPP.listen: called a second time: doing nothing
7/9/16 4:18:27.079 PM Docker[87188]: TCP/IP ready
7/9/16 4:18:27.079 PM Docker[87188]: stack connected
7/9/16 4:18:27.080 PM Docker[87190]: virtio-net-vpnkit: magic=VMN3T version=1 commit=0123456789012345678901234567890123456789
7/9/16 4:18:27.080 PM Docker[87190]: mirage_block_open file:///Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2 buffered = true
7/9/16 4:18:27.081 PM Docker[87190]: mirage_block_open returning 0
7/9/16 4:18:27.081 PM Docker[87190]: mirage_block_stat
7/9/16 4:18:27.081 PM Docker[87190]: vsock init 7:0 = /Users/rb/Library/Containers/com.docker.docker/Data, guest_cid = 3
7/9/16 4:18:29.152 PM Docker[87190]:
rdmsr to register 0x34 on vcpu 1
7/9/16 4:18:29.854 PM Docker[87190]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:18:30.356 PM Docker[87190]: Docker is not responding: Get http://./info: write unix ->/Users/rb/Library/Containers/com.docker.docker/Data/*00000003.00000948: write: broken pipe: waiting 0.5s
7/9/16 4:18:30.860 PM Docker[87190]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:18:31.361 PM Docker[87190]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:18:31.865 PM Docker[87190]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:18:32.319 PM Docker[87187]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Users
7/9/16 4:18:32.321 PM Docker[87187]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Volumes
7/9/16 4:18:32.322 PM Docker[87187]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /tmp
7/9/16 4:18:32.324 PM Docker[87187]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /private
7/9/16 4:18:32.327 PM Docker[87187]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Mac
7/9/16 4:18:32.361 PM Docker[87188]: Using protocol TwoThousand msize 8192
7/9/16 4:18:32.367 PM Docker[87190]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:18:34.358 PM Docker[87190]: Docker is responding
7/9/16 4:18:34.375 PM Docker[87189]: VM started at 2016-07-09 16:18:34 -0400 EDT
7/9/16 4:18:34.459 PM Docker[87165]: dockerState = Starting
7/9/16 4:18:44.457 PM Docker[87187]: Creating resource Entry(sonarr)
7/9/16 4:18:44.458 PM Docker[87187]: Write offset=0 data=[sonarr:/Users/rb/Containers/Volumes/sonarr/config:/Users/rb/Containers/Volumes/sonarr/downloads:/Users/rb/Containers/Volumes/sonarr/tv] to file
7/9/16 4:18:44.458 PM Docker[87187]: Volume.start sonarr (paths = [/Users/rb/Containers/Volumes/sonarr/config, /Users/rb/Containers/Volumes/sonarr/downloads, /Users/rb/Containers/Volumes/sonarr/tv])
7/9/16 4:18:44.461 PM Docker[87187]: Created instance sonarr
7/9/16 4:18:44.510 PM Docker[87188]: Creating resource Entry(tcp:0.0.0.0:32751:tcp:172.17.0.2:8989)
7/9/16 4:18:44.512 PM Docker[87188]: Write offset=0 data=[tcp:0.0.0.0:32751:tcp:172.17.0.2:8989] to file
7/9/16 4:18:44.513 PM Docker[87188]: attempting a best-effort bind of ::1:32751
7/9/16 4:18:44.513 PM Docker[87188]: Created instance tcp:0.0.0.0:32751:tcp:172.17.0.2:8989
7/9/16 4:18:44.819 PM Docker[87187]: Creating resource Entry(nzbget)
7/9/16 4:18:44.820 PM Docker[87187]: Write offset=0 data=[nzbget:/Users/rb/Containers/Volumes/nzbget/config:/Users/rb/Containers/Volumes/nzbget/downloads] to file
7/9/16 4:18:44.820 PM Docker[87187]: Volume.start nzbget (paths = [/Users/rb/Containers/Volumes/nzbget/config, /Users/rb/Containers/Volumes/nzbget/downloads])
7/9/16 4:18:44.822 PM Docker[87187]: Created instance nzbget
7/9/16 4:18:44.895 PM Docker[87188]: Creating resource Entry(tcp:0.0.0.0:32750:tcp:172.17.0.3:6789)
7/9/16 4:18:44.897 PM Docker[87188]: Write offset=0 data=[tcp:0.0.0.0:32750:tcp:172.17.0.3:6789] to file
7/9/16 4:18:44.898 PM Docker[87188]: attempting a best-effort bind of ::1:32750
7/9/16 4:18:44.898 PM Docker[87188]: Created instance tcp:0.0.0.0:32750:tcp:172.17.0.3:6789
7/9/16 4:19:42.152 PM Docker[87188]: Socket.TCPV4.read 128.237.157.9:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:19:43.850 PM Docker[87188]: Socket.TCPV4.read 128.237.157.10:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:19:44.138 PM Docker[87188]: Socket.TCPV4.read 128.237.157.10:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:19:49.937 PM Docker[87188]: Socket.TCPV4.read 128.237.157.9:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:19:49.967 PM Docker[87188]: Socket.TCPV4.read 128.237.157.9:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:20:02.877 PM Docker[87188]: Socket.TCPV4.read 128.237.157.10:80: caught Uwt.Uwt_error(Uwt.ETIMEDOUT, “uwt_read”, “”) returning Eof
7/9/16 4:20:46.000 PM kernel[0]: process com.docker.hyper[87193] caught causing excessive wakeups. Observed wakeups rate (per sec): 322; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45003
7/9/16 4:20:51.990 PM spindump[708]: Saved wakeups_resource.diag report for com.docker.hyperkit version ??? (???) to /Library/Logs/DiagnosticReports/com.docker.hyperkit_2016-07-09-162051_iMac.wakeups_resource.diag
7/9/16 4:22:02.449 PM Docker[87188]: dropping unexpected TCP packet sent from 172.17.0.3:51234 to 192.73.23.18:80 (valid sources = 192.168.65.2, 0.0.0.0)

message repeated a lot…

7/9/16 4:25:45.585 PM Docker[87187]: Unknown exception caught: End_of_file
7/9/16 4:25:45.585 PM Docker[87187]: Fatal unexpected exception: End_of_file
7/9/16 4:25:45.624 PM Docker[87178]: Reap com.docker.osxfs (pid 87187): exit status 1
7/9/16 4:25:46.627 PM Docker[87178]: Stop 1 children with order 1: com.docker.driver.amd64-linux (pid 87190)
7/9/16 4:25:46.627 PM Docker[87178]: Signal terminated to com.docker.driver.amd64-linux (pid 87190)
7/9/16 4:25:46.630 PM Docker[87190]: sending SIGTERM to com.docker.hyperkit pid 87193
7/9/16 4:25:46.826 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:46.831 PM Docker[87188]: Socket.Pipe.write /Users/rb/Library/Containers/com.docker.docker/Data/@connect: caught Uwt.Uwt_error(Uwt.EPIPE, “write”, “”) returning Eof
7/9/16 4:25:46.831 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:46.836 PM Docker[87188]: Socket.Pipe.write /Users/rb/Library/Containers/com.docker.docker/Data/@connect: caught Uwt.Uwt_error(Uwt.EPIPE, “write”, “”) returning Eof
7/9/16 4:25:46.837 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:46.854 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:46.856 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:46.859 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:47.146 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:47.155 PM Docker[87188]: Socket.Stream: caught Uwt.Uwt_error(Uwt.ENOTCONN, “shutdown”, “”)
7/9/16 4:25:49.023 PM Docker[87190]: virtio-net-vpnkit: initialising, opts=“uuid=16d3ffc8-26af-432c-89c2-c39742559d63,path=/Users/rb/Library/Containers/com.docker.docker/Data/s50,macfile=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/mac.0"
7/9/16 4:25:49.023 PM Docker[87190]: Interface will have uuid 16d3ffc8-26af-432c-89c2-c39742559d63
7/9/16 4:25:49.023 PM Docker[87190]: Connection established with MAC=c0:ff:ee:c0:ff:ee and MTU 1500
7/9/16 4:25:49.023 PM Docker[87190]: virtio-9p: initialising path=/Users/rb/Library/Containers/com.docker.docker/Data/s40,tag=db
7/9/16 4:25:49.023 PM Docker[87190]: virtio-9p: initialising path=/Users/rb/Library/Containers/com.docker.docker/Data/s51,tag=port
7/9/16 4:25:49.023 PM Docker[87190]: linkname /Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty
7/9/16 4:25:49.023 PM Docker[87190]: COM1 connected to /dev/ttys000
7/9/16 4:25:49.023 PM Docker[87190]: COM1 linked to /Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty
7/9/16 4:25:49.059 PM Docker[87188]: PPP.listen: closing connection
7/9/16 4:25:49.081 PM Docker[87189]: VM shutdown at 2016-07-09 16:25:49 -0400 EDT
7/9/16 4:25:49.086 PM Docker[87178]: Reap com.docker.driver.amd64-linux (pid 87190): exit status 0
7/9/16 4:25:49.103 PM Docker[87178]: Stop 2 children with order 2: com.docker.osxfs (pid 87187), com.docker.slirp (pid 87188)
7/9/16 4:25:49.103 PM Docker[87178]: Signal terminated to com.docker.slirp (pid 87188)
7/9/16 4:25:49.118 PM Docker[87178]: Reap com.docker.slirp (pid 87188): signal: terminated
7/9/16 4:25:49.124 PM Docker[87165]: dockerState = Starting
7/9/16 4:25:49.203 PM Docker[87178]: Starting com.docker.osxfs, com.docker.slirp, com.docker.driver.amd64-linux
7/9/16 4:25:49.209 PM Docker[87178]: Start com.docker.osxfs (pid 87341)
7/9/16 4:25:49.214 PM Docker[87178]: Start com.docker.slirp (pid 87342)
7/9/16 4:25:49.220 PM Docker[87178]: Start com.docker.driver.amd64-linux (pid 87343)
7/9/16 4:25:49.244 PM Docker[87341]: Logging to Apple System Log
7/9/16 4:25:49.263 PM Docker[87343]: Acquired hypervisor lock
7/9/16 4:25:49.266 PM Docker[87343]: Docker is not responding: Get http://./info: dial unix /Users/rb/Library/Containers/com.docker.docker/Data/*00000003.00000948: connect: connection refused: waiting 0.5s
7/9/16 4:25:49.273 PM Docker[87342]: Logging to Apple System Log
7/9/16 4:25:49.273 PM Docker[87342]: Setting handler to ignore all SIGPIPE signals
7/9/16 4:25:49.274 PM Docker[87342]: Setting soft fd limit to 10240
7/9/16 4:25:49.274 PM Docker[87342]: starting port_forwarding port_control_path:fd:4 vsock_path:/Users/rb/Library/Containers/com.docker.docker/Data/@connect
7/9/16 4:25:49.275 PM Docker[87342]: attempting to reconnect to database
7/9/16 4:25:49.277 PM Docker[87342]: reconnected transport layer
7/9/16 4:25:49.278 PM Docker[87342]: allowing binds to any IP addresses
7/9/16 4:25:49.280 PM Docker[87342]: Creating slirp server pcap_settings:disabled peer_ip:192.168.65.2 local_ip:192.168.65.1
7/9/16 4:25:49.361 PM Docker[87343]: hypervisor: native
7/9/16 4:25:49.361 PM Docker[87343]: filesystem: osxfs
7/9/16 4:25:49.361 PM Docker[87343]: network: hybrid
7/9/16 4:25:49.362 PM Docker[87341]: Using protocol TwoThousand msize 16384
7/9/16 4:25:49.364 PM Docker[87343]: Hypervisor: native; BootProtocol: direct; UefiBootDisk: /Users/rb/UefiBoot.qcow2
7/9/16 4:25:49.364 PM Docker[87343]: Launching: /Applications/Docker.app/Contents/MacOS/com.docker.hyperkit -A -m 2G -c 2 -u -s 0:0,hostbridge -s 31,lpc -s 2:0,virtio-vpnkit,uuid=16d3ffc8-26af-432c-89c2-c39742559d63,path=/Users/rb/Library/Containers/com.docker.docker/Data/s50,macfile=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/mac.0 -s 3,virtio-blk,file:///Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2,format=qcow -s 4,virtio-9p,path=/Users/rb/Library/Containers/com.docker.docker/Data/s40,tag=db -s 5,virtio-rnd -s 6,virtio-9p,path=/Users/rb/Library/Containers/com.docker.docker/Data/s51,tag=port -s 7,virtio-sock,guest_cid=3,path=/Users/rb/Library/Containers/com.docker.docker/Data,guest_forwards=2376;1525 -l com1,autopty=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty,log=/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/console-ring -f kexec,/Applications/Docker.app/Contents/Resources/moby/vmlinuz64,/Applications/Docker.app/Contents/Resources/moby/initrd.img,earlyprintk=serial console=ttyS0 com.docker.driverDir=”/Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux", com.docker.database=“com.docker.driver.amd64-linux” ntp=gateway -F /Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/hypervisor.pid
7/9/16 4:25:49.400 PM Docker[87342]: PPP.negotiate: received ((magic VMN3T)(version 1)(commit ec40b14c72adc0bff3b01fa8886dae7f2eee1541))
7/9/16 4:25:49.400 PM Docker[87342]: PPP.negotiate: received (Ethernet 16d3ffc8-26af-432c-89c2-c39742559d63)
7/9/16 4:25:49.400 PM Docker[87343]: virtio-net-vpnkit: magic=VMN3T version=1 commit=0123456789012345678901234567890123456789
7/9/16 4:25:49.400 PM Docker[87342]: PPP.negotiate: sending ((mtu 1500)(max_packet_size 1550)(client_macaddr c0:ff:ee:c0:ff:ee))
7/9/16 4:25:49.401 PM Docker[87342]: PPP.listen: called a second time: doing nothing
7/9/16 4:25:49.401 PM Docker[87342]: TCP/IP ready
7/9/16 4:25:49.401 PM Docker[87342]: stack connected
7/9/16 4:25:49.401 PM Docker[87343]: mirage_block_open file:///Users/rb/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2 buffered = true
7/9/16 4:25:49.402 PM Docker[87343]: mirage_block_open returning 0
7/9/16 4:25:49.402 PM Docker[87343]: mirage_block_stat
7/9/16 4:25:49.402 PM Docker[87343]: vsock init 7:0 = /Users/rb/Library/Containers/com.docker.docker/Data, guest_cid = 3
7/9/16 4:25:53.825 PM Docker[87343]:
rdmsr to register 0x34 on vcpu 1
7/9/16 4:25:54.818 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:55.321 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:55.830 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:56.335 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:56.837 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:57.341 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:57.847 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:58.348 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:58.849 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:59.350 PM Docker[87343]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
7/9/16 4:25:59.606 PM Docker[87341]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Users
7/9/16 4:25:59.610 PM Docker[87341]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Volumes
7/9/16 4:25:59.614 PM Docker[87341]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /tmp
7/9/16 4:25:59.616 PM Docker[87341]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /private
7/9/16 4:25:59.621 PM Docker[87341]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Mac
7/9/16 4:25:59.691 PM Docker[87342]: Using protocol TwoThousand msize 8192
7/9/16 4:26:02.472 PM Docker[87343]: Docker is responding
7/9/16 4:26:02.492 PM Docker[87189]: VM started at 2016-07-09 16:26:02 -0400 EDT
7/9/16 4:26:02.514 PM Docker[87165]: dockerState = Running
7/9/16 4:26:03.000 PM kernel[0]: process docker[87289] caught causing excessive wakeups. Observed wakeups rate (per sec): 245; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 45001
7/9/16 4:26:07.170 PM Docker[87342]: failed to establish 9P connection: Caught EOF on underlying FLOW
7/9/16 4:26:07.170 PM Docker[87370]: EOF reading packet from Unix domain socket: closing
7/9/16 4:26:07.171 PM Docker[87370]: Failed to read hello from client
7/9/16 4:26:13.889 PM spindump[708]: Saved wakeups_resource.diag report for docker version ??? (???) to /Library/Logs/DiagnosticReports/docker_2016-07-09-162613_iMac.wakeups_resource.diag
7/9/16 4:26:14.006 PM Docker[87342]: TCP 104.239.220.248:80 > 192.168.65.2:55346 proxy failed with flow proxy b: Connection refused
7/9/16 4:27:18.502 PM Docker[87342]: failed to establish 9P connection: Caught EOF on underlying FLOW
7/9/16 4:27:18.502 PM Docker[87437]: EOF reading packet from Unix domain socket: closing
7/9/16 4:27:18.502 PM Docker[87437]: Failed to read hello from client
7/9/16 4:27:24.919 PM Docker[87342]: TCP 104.239.220.248:80 > 192.168.65.2:55356 proxy failed with flow proxy b: Connection refused

Steps to reproduce the behavior

  1. running container muxponder/nzbget:custom
  2. download file

Additional info

This didn’t start until one of the more recent beta releases.