docker / for-mac

Bug reports for Docker Desktop for Mac
https://www.docker.com/products/docker#/mac
2.43k stars 117 forks source link

Docker for mac not starting after latest version upgrade Version 1.12.1 (build: 12133) 2d5b4d9c3daa089e3869e6355a47dd96dbf39856 #710

Closed mukteshkrmishra closed 7 years ago

mukteshkrmishra commented 8 years ago

Hi,

After updating to latest version, docker for mac is not starting. App is trying to start forever with following error in logs: Docker is not responding: Get http://./info: EOF: waiting 0.5s

Please note after factory resetting issue got resolved, but it deleted all my images.

Version 1.12.1 (build: 12133) 2d5b4d9c3daa089e3869e6355a47dd96dbf39856

Complete start up logs:

9/27/16 11:37:46.126 AM Docker[1974]: Application version: 1.12.1 (12133)
9/27/16 11:37:46.126 AM Docker[1974]: Administrator user: false
9/27/16 11:37:46.301 AM Docker[1974]: OSX Version: Version 10.11.6 (Build 15G1004)
9/27/16 11:37:46.469 AM Docker[1974]: migrator: start migration process
9/27/16 11:37:46.471 AM Docker[1974]: migrator: previous install detected
9/27/16 11:37:46.471 AM Docker[1974]: migrator: previous version is 1.12.0-rc2-beta17
9/27/16 11:37:46.471 AM Docker[1974]: migrator: no migration needed, you are good to go!
9/27/16 11:37:46.471 AM Docker[1974]: migrator: successfully updated from version 1.12.0-rc2-beta17 to 1.12.1
9/27/16 11:37:46.472 AM Docker[1974]: migrator: end of migration process
9/27/16 11:37:46.478 AM Docker[1974]: event tracker initialized
9/27/16 11:37:46.482 AM Docker[1974]: Bundle path: /Applications/Docker.app
9/27/16 11:37:46.482 AM Docker[1983]: Client reports version 1, commit 2d5b4d9c3daa089e3869e6355a47dd96dbf39856
9/27/16 11:37:46.483 AM Docker[1983]: EOF reading packet from Unix domain socket: closing
9/27/16 11:37:46.483 AM Docker[1974]: com.docker.docker commit: 2d5b4d9c3daa089e3869e6355a47dd96dbf39856 wants version 18
9/27/16 11:37:46.483 AM Docker[1974]: com.docker.vmnetd commit: 2d5b4d9c3daa089e3869e6355a47dd96dbf39856 has version 18
9/27/16 11:37:46.483 AM Docker[1983]: Failed to read command from client
9/27/16 11:37:46.483 AM Docker[1974]: probe of /var/tmp/com.docker.vmnetd.socket successful: not reinstalling component
9/27/16 11:37:46.483 AM Docker[1984]: Client reports version 1, commit 2d5b4d9c3daa089e3869e6355a47dd96dbf39856
9/27/16 11:37:46.484 AM Docker[1984]: client with uid 1776612818 requests com.docker.vmnetd install symlinks
9/27/16 11:37:46.484 AM Docker[1984]: File /usr/local/bin/docker is a symlink
9/27/16 11:37:46.485 AM Docker[1984]: Client supplied container path /Users/gdx432/Library/Containers/com.docker.docker/Data
9/27/16 11:37:46.485 AM Docker[1984]: File /var/run/docker.sock is a symlink or a socket
9/27/16 11:37:46.485 AM Docker[1984]: Symlinking /var/run/docker.sock to /Users/gdx432/Library/Containers/com.docker.docker/Data/s60
9/27/16 11:37:46.485 AM Docker[1984]: File /usr/local/bin/docker-compose is a symlink
9/27/16 11:37:46.485 AM Docker[1984]: Client supplied container path /Users/gdx432/Library/Containers/com.docker.docker/Data
9/27/16 11:37:46.485 AM Docker[1984]: File /var/run/docker.sock is a symlink or a socket
9/27/16 11:37:46.486 AM Docker[1984]: Symlinking /var/run/docker.sock to /Users/gdx432/Library/Containers/com.docker.docker/Data/s60
9/27/16 11:37:46.486 AM Docker[1984]: File /usr/local/bin/notary is a symlink
9/27/16 11:37:46.486 AM Docker[1984]: Client supplied container path /Users/gdx432/Library/Containers/com.docker.docker/Data
9/27/16 11:37:46.486 AM Docker[1984]: File /var/run/docker.sock is a symlink or a socket
9/27/16 11:37:46.486 AM Docker[1984]: Symlinking /var/run/docker.sock to /Users/gdx432/Library/Containers/com.docker.docker/Data/s60
9/27/16 11:37:46.486 AM Docker[1984]: File /usr/local/bin/docker-machine is a symlink
9/27/16 11:37:46.486 AM Docker[1984]: Client supplied container path /Users/gdx432/Library/Containers/com.docker.docker/Data
9/27/16 11:37:46.487 AM Docker[1984]: File /var/run/docker.sock is a symlink or a socket
9/27/16 11:37:46.487 AM Docker[1984]: Symlinking /var/run/docker.sock to /Users/gdx432/Library/Containers/com.docker.docker/Data/s60
9/27/16 11:37:46.487 AM Docker[1974]: Symlinks are valid.
9/27/16 11:37:46.495 AM lsd[874]: LaunchServices: Could not store lsd-identifiers file at /private/var/db/lsd/com.apple.lsdschemes.plist
9/27/16 11:37:46.497 AM Docker[1974]: com.docker.osx.hyperkit.linux launched with PID 1986
9/27/16 11:37:46.509 AM Docker[1986]: Acquired task manager lock
9/27/16 11:37:46.509 AM Docker[1986]: Maximum number of file descriptors is 10240
9/27/16 11:37:46.509 AM Docker[1985]: dial unix /Users/gdx432/Library/Containers/com.docker.docker/Data/s20: connect: connection refused
9/27/16 11:37:46.514 AM Docker[1986]: Removing leaked pidfile com.docker.hyperkit
9/27/16 11:37:46.515 AM Docker[1986]: Starting com.docker.db, com.docker.osxfs, com.docker.slirp, com.docker.osx.hyperkit.linux, com.docker.driver.amd64-linux
9/27/16 11:37:46.518 AM Docker[1986]: Start com.docker.db (pid 1989)
9/27/16 11:37:46.520 AM Docker[1986]: Start com.docker.osxfs (pid 1990)
9/27/16 11:37:46.523 AM Docker[1986]: Start com.docker.slirp (pid 1991)
9/27/16 11:37:46.525 AM Docker[1986]: Start com.docker.osx.hyperkit.linux (pid 1992)
9/27/16 11:37:46.527 AM Docker[1986]: Start com.docker.driver.amd64-linux (pid 1993)
9/27/16 11:37:46.527 AM Docker[1990]: Logging to Apple System Log
9/27/16 11:37:46.529 AM Docker[1991]: Logging to Apple System Log
9/27/16 11:37:46.529 AM Docker[1991]: Setting handler to ignore all SIGPIPE signals
9/27/16 11:37:46.529 AM Docker[1991]: vpnkit version 0c7cf02 with hostnet version local  uwt version 0.0.3 hvsock version 0.10.0 
9/27/16 11:37:46.529 AM Docker[1991]: starting port_forwarding port_control_url:fd:4 max_connections:Some 900 vsock_path:/Users/gdx432/Library/Containers/com.docker.docker/Data/@connect
9/27/16 11:37:46.530 AM Docker[1991]: hosts file has bindings for localhost broadcasthost localhost access.capitalone.com
9/27/16 11:37:46.533 AM Docker[1992]: API server starting
9/27/16 11:37:46.534 AM Docker[1992]: 🍀 socket path is: /Users/gdx432/Library/Containers/com.docker.docker/Data/s20
9/27/16 11:37:46.534 AM Docker[1992]: API socket removed
9/27/16 11:37:46.537 AM Docker[1992]: VM shutdown at 2016-09-27 11:36:58 -0700 PDT
9/27/16 11:37:46.544 AM Docker[1993]: Acquired hypervisor lock
9/27/16 11:37:46.658 AM Docker[1974]: frontend process failed
9/27/16 11:37:46.662 AM Docker[1986]: Reap com.docker.driver.amd64-linux (pid 1993): exit status 2
9/27/16 11:37:47.040 AM ntpd[422]: sigio_handler: sigio_handler_active != 0
9/27/16 11:37:47.040 AM ntpd[422]: sigio_handler: sigio_handler_active != 1
9/27/16 11:37:47.663 AM Docker[1986]: Stop 1 children with order 1: com.docker.driver.amd64-linux (pid 1993)
9/27/16 11:37:47.663 AM Docker[1986]: Starting com.docker.driver.amd64-linux
9/27/16 11:37:47.667 AM Docker[1986]: Start com.docker.driver.amd64-linux (pid 1998)
9/27/16 11:37:47.685 AM Docker[1998]: Acquired hypervisor lock
9/27/16 11:37:47.686 AM com.docker.driver.amd64-linux[1998]: com.docker.driver.amd64-linux(1998,0x7fff7a253000) malloc: *** error for object 0x490fef0: incorrect checksum for freed object - object was probably modified after being freed.
*** set a breakpoint in malloc_error_break to debug
9/27/16 11:37:47.690 AM Docker[1986]: Reap com.docker.driver.amd64-linux (pid 1998): exit status 2
9/27/16 11:37:48.691 AM Docker[1986]: Stop 1 children with order 1: com.docker.driver.amd64-linux (pid 1998)
9/27/16 11:37:48.691 AM Docker[1986]: Starting com.docker.driver.amd64-linux
9/27/16 11:37:48.693 AM Docker[1986]: Start com.docker.driver.amd64-linux (pid 2002)
9/27/16 11:37:48.712 AM Docker[2002]: Acquired hypervisor lock
9/27/16 11:37:48.714 AM com.docker.driver.amd64-linux[2002]: detected source and destination buffer overlap
9/27/16 11:37:48.718 AM Docker[1986]: Reap com.docker.driver.amd64-linux (pid 2002): exit status 2
9/27/16 11:37:49.722 AM Docker[1986]: Stop 1 children with order 1: com.docker.driver.amd64-linux (pid 2002)
9/27/16 11:37:49.722 AM Docker[1986]: Starting com.docker.driver.amd64-linux
9/27/16 11:37:49.725 AM Docker[1986]: Start com.docker.driver.amd64-linux (pid 2004)
9/27/16 11:37:49.742 AM Docker[2004]: Acquired hypervisor lock
9/27/16 11:37:49.745 AM Docker[2004]: Docker is not responding: Get http://./info: dial unix /Users/gdx432/Library/Containers/com.docker.docker/Data/*00000003.00000948: connect: connection refused: waiting 0.5s
9/27/16 11:37:49.753 AM Docker[2004]: OSX version = 10.11.6, default value of on-sleep = freeze
9/27/16 11:37:49.777 AM Docker[2004]: hypervisor: native
9/27/16 11:37:49.777 AM Docker[2004]: filesystem: osxfs
9/27/16 11:37:49.777 AM Docker[2004]: network: hybrid
9/27/16 11:37:49.778 AM Docker[1990]: Using protocol TwoThousand msize 16384
9/27/16 11:37:49.778 AM Docker[2004]: Hypervisor: native; BootProtocol: direct; UefiBootDisk: /Users/gdx432/UefiBoot.qcow2
9/27/16 11:37:49.778 AM Docker[2004]: Syslog socket is /Users/gdx432/Library/Containers/com.docker.docker/Data/*00000002.00000202
9/27/16 11:37:49.779 AM Docker[2004]: Logfile is /Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/syslog
9/27/16 11:37:49.781 AM Docker[2004]: Launched[2008]: /Applications/Docker.app/Contents/MacOS/com.docker.hyperkit -A -m 2G -c 4 -u -s 0:0,hostbridge -s 31,lpc -s 2:0,virtio-vpnkit,uuid=708c2f9d-b434-49d7-8151-fd11c697b1cf,path=/Users/gdx432/Library/Containers/com.docker.docker/Data/s50,macfile=/Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/mac.0 -s 3,virtio-blk,file:///Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2,format=qcow -s 4,virtio-9p,path=/Users/gdx432/Library/Containers/com.docker.docker/Data/s40,tag=db -s 5,virtio-rnd -s 6,virtio-9p,path=/Users/gdx432/Library/Containers/com.docker.docker/Data/s51,tag=port -s 7,virtio-sock,guest_cid=3,path=/Users/gdx432/Library/Containers/com.docker.docker/Data,guest_forwards=2376;1525 -l com1,autopty=/Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty,log=/Users/gdx432/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.driver="com.docker.driver.amd64-linux", com.docker.database="com.docker.driver.amd64-linux" ntp=gateway mobyplatform=mac -F /Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/hypervisor.pid
9/27/16 11:37:49.784 AM Docker[2004]: SC database lists DNS servers: 75.75.75.75, 75.75.76.76, 2001:558:feed::1, 2001:558:feed::2
9/27/16 11:37:49.784 AM Docker[2004]: SC database lists search domains: cof.ds.capitalone.com kdc.capitalone.com ds.capitalone.com capitalone.com
9/27/16 11:37:49.791 AM Docker[1991]: attempting to reconnect to database
9/27/16 11:37:49.791 AM Docker[1991]: reconnected transport layer
9/27/16 11:37:49.792 AM Docker[1991]: updating search domains to cof.ds.capitalone.com kdc.capitalone.com ds.capitalone.com capitalone.com
9/27/16 11:37:49.792 AM Docker[1991]: updating resolvers to nameserver 75.75.75.75#53
nameserver 75.75.76.76#53
nameserver 2001:558:feed::1#53
nameserver 2001:558:feed::2#53
9/27/16 11:37:49.792 AM Docker[1991]: using DNS forwarders on 75.75.75.75#53; 75.75.76.76#53; 2001:558:feed::1#53; 2001:558:feed::2#53
9/27/16 11:37:49.792 AM Docker[1991]: allowing binds to any IP addresses
9/27/16 11:37:49.793 AM Docker[1991]: Creating slirp server pcap_settings:disabled peer_ip:192.168.65.2 local_ip:192.168.65.1 domain_search:cof.ds.capitalone.com kdc.capitalone.com ds.capitalone.com capitalone.com
9/27/16 11:37:49.793 AM Docker[1991]: PPP.negotiate: received ((magic VMN3T)(version 1)(commit 2d5b4d9c3daa089e3869e6355a47dd96dbf39856))
9/27/16 11:37:49.793 AM Docker[1991]: PPP.negotiate: received (Ethernet 708c2f9d-b434-49d7-8151-fd11c697b1cf)
9/27/16 11:37:49.793 AM Docker[2004]: virtio-net-vpnkit: magic=VMN3T version=1 commit=0123456789012345678901234567890123456789
9/27/16 11:37:49.793 AM Docker[1991]: PPP.negotiate: sending ((mtu 1500)(max_packet_size 1550)(client_macaddr c0:ff:ee:c0:ff:ee))
9/27/16 11:37:49.793 AM Docker[2004]: mirage_block_open file:///Users/gdx432/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/Docker.qcow2 buffered = true
9/27/16 11:37:49.794 AM Docker[2004]: mirage_block_open returning 0
9/27/16 11:37:49.794 AM Docker[2004]: mirage_block_stat
9/27/16 11:37:49.794 AM Docker[2004]: vsock init 7:0 = /Users/gdx432/Library/Containers/com.docker.docker/Data, guest_cid = 3
9/27/16 11:37:49.794 AM Docker[1991]: PPP.listen: called a second time: doing nothing
9/27/16 11:37:49.794 AM Docker[1991]: TCP/IP ready
9/27/16 11:37:49.795 AM Docker[1991]: stack connected
9/27/16 11:37:51.961 AM Docker[2004]: 
rdmsr to register 0x34 on vcpu 0
9/27/16 11:37:52.554 AM Docker[2004]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
9/27/16 11:37:53.058 AM Docker[2004]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
9/27/16 11:37:55.608 AM Docker[1991]: BOOTREQUEST from c0:ff:ee:c0:ff:ee
9/27/16 11:37:55.608 AM Docker[1991]: BOOTREPLY to c0:ff:ee:c0:ff:ee yiddr 192.168.65.2 siddr 192.168.65.1 dns 192.168.65.1, 192.168.65.10, 192.168.65.9, 192.168.65.8, 192.168.65.7, 192.168.65.6, 192.168.65.5, 192.168.65.4, 192.168.65.3 router 192.168.65.1 domain local
9/27/16 11:37:55.864 AM Docker[1990]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Users
9/27/16 11:37:55.865 AM Docker[1990]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /Volumes
9/27/16 11:37:55.866 AM Docker[1990]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /tmp
9/27/16 11:37:55.867 AM Docker[1990]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /private
9/27/16 11:37:55.868 AM Docker[1990]: transfused: mount /bin/fusermount -o allow_other,max_read=1048576,subtype=osxfs /host_docker_app
9/27/16 11:37:55.868 AM Docker[1990]: Negotiated transfuse notification channel for /Users
9/27/16 11:37:55.868 AM Docker[1990]: Negotiated transfuse notification channel for /Volumes
9/27/16 11:37:55.868 AM Docker[1990]: Negotiated transfuse notification channel for /tmp
9/27/16 11:37:55.869 AM Docker[1990]: Negotiated transfuse notification channel for /private
9/27/16 11:37:55.869 AM Docker[1990]: Negotiated transfuse notification channel for /host_docker_app
9/27/16 11:37:55.869 AM Docker[1990]: sending continue to client
9/27/16 11:37:55.908 AM Docker[1991]: Using protocol TwoThousand msize 8192
9/27/16 11:37:57.328 AM Docker[2004]: Docker is not responding: Get http://./info: EOF: waiting 0.5s
dsheets commented 8 years ago

Could you please run Diagnose & Feedback from the :whale: menu, select Diagnose & Upload, and paste the results of the diagnostic run (including diagnostic ID) back here? This will help us understand what is happening with the Docker application. Thanks!

ijc commented 7 years ago

:+1: to the request for a diagnostics upload.

In the logs given I do see:

9/27/16 11:37:47.686 AM com.docker.driver.amd64-linux[1998]: com.docker.driver.amd64-linux(1998,0x7fff7a253000) malloc: *** error for object 0x490fef0: incorrect checksum for freed object - object was probably modified after being freed.
*** set a breakpoint in malloc_error_break to debug

There were some related fixes in beta29.2, if you are happy to try the beta version then it would be interesting to know if you can still reproduce with that version. Also beta28 onwards collect more information relevant to these kinds of issues so if it reproduces there then a diagnostic upload from the current beta would be more useful than stable at this time.

ijc commented 7 years ago

The malloc related issues were fixed in beta29 and stable 1.2.3. Closing, thanks.

docker-robott commented 4 years ago

Closed issues are locked after 30 days of inactivity. This helps our team focus on active issues.

If you have found a problem that seems similar to this, please open a new issue.

Send feedback to Docker Community Slack channels #docker-for-mac or #docker-for-windows. /lifecycle locked