Docker Community Forums

Share and learn in the Docker community.

Unable to access volumes using osxfs ("/Mac: Socket not connected") - [f]stat[v]fs family of functions

(Tomfrost) #5

I also don’t have a /Mac mountpoint – would be happy to debug, though I’m uncertain how to access the vm directly. I untarred/ungzipped the logs and dumped out com.docker.osxfs.log:

2016-04-05T23:29:29.665383-04 Info - accepted connection
2016-04-05T23:29:29.665440-04 Info - C ((tag ()) (payload (Version ((msize 65536) (version TwoThousand)))))
2016-04-05T23:29:29.665468-04 Info - Using protocol TwoThousand msize 16384
2016-04-05T23:29:29.665492-04 Info - C ((tag (1))
2016-04-05T23:29:29.665515-04 Info -    (payload
2016-04-05T23:29:29.665538-04 Info -     (Attach ((fid 1) (afid -1) (uname anyone) (aname /) (n_uname ())))))
2016-04-05T23:29:29.665560-04 Info - Successfully negotiated a connection.
2016-04-05T23:29:32.235585-04 Info - C ((tag ()) (payload (Version ((msize 32768) (version TwoThousand)))))
2016-04-05T23:29:32.235637-04 Info - Using protocol TwoThousand msize 32768
2016-04-05T23:29:32.235665-04 Info - C ((tag (1))
2016-04-05T23:29:32.235689-04 Info -    (payload
2016-04-05T23:29:32.235714-04 Info -     (Attach ((fid 0) (afid -1) (uname nobody) (aname "") (n_uname ())))))
2016-04-05T23:29:32.235737-04 Info - Negotiated a connection with msize 32768.
2016-04-05T23:29:32.772185-04 Error - Event thread is 1092
2016-04-05T23:29:32.782855-04 Error - max_readahead = 32741 max_write = 32680
2016-04-05T23:29:32.782945-04 Error - osxfs tracing: OFF
2016-04-05T23:29:59.641801-04 Error - com.docker.osxfs: [ERROR] Volume.start b2bddbfab9a8053bad59a9b9bd0e0f4b42dc7d4df17a7d124ecfb83b0efdd77c (paths = [/Users/tom, /Users/tom/Projects/userhub])
2016-04-05T23:29:59.641905-04 Error - Adding watch for /Users/tom
2016-04-05T23:29:59.641964-04 Error - Volume: watching /Users/tom since now
2016-04-05T23:29:59.642014-04 Error - Adding watch for /Users/tom/Projects/userhub
2016-04-05T23:30:00.385952-04 Error - start_watch: got event from stream
2016-04-05T23:33:55.946644-04 Error - com.docker.osxfs: [ERROR] Volume.stop b2bddbfab9a8053bad59a9b9bd0e0f4b42dc7d4df17a7d124ecfb83b0efdd77c (paths = [/Users/tom, /Users/tom/Projects/userhub])
2016-04-05T23:33:55.946772-04 Error - Removing watch for /Users/tom
2016-04-05T23:33:55.946839-04 Error - about to flush watcher for /Users/tom
2016-04-05T23:33:55.946904-04 Error - 2016-04-05 23:33 com.docker.osxfs[95182] (FSEvents.framework) FSEventStreamFlushSync(): failed assertion '(SInt64)last_id > 0LL'
2016-04-05T23:33:55.946963-04 Error - stopped watching /Users/tom
2016-04-05T23:33:55.947021-04 Error - restarting watch of /Users/tom/Projects/userhub
2016-04-05T23:33:55.947079-04 Error - Volume: watching /Users/tom/Projects/userhub since 18158642065532649396
2016-04-05T23:33:55.947135-04 Error - Stream ended (continue)
2016-04-05T23:33:55.947190-04 Error - Removing watch for /Users/tom/Projects/userhub
2016-04-05T23:33:55.947246-04 Error - about to flush watcher for /Users/tom/Projects/userhub
2016-04-05T23:33:55.947305-04 Error - 2016-04-05 23:33 com.docker.osxfs[95182] (FSEvents.framework) FSEventStreamFlushSync:1(streamRef = 0x7fc2020fb120): ERROR: CFRunLoopRunInMode() => The run loop mode mode has no sources or timers. (1)
2016-04-05T23:33:55.947364-04 Error - stopped watching /Users/tom/Projects/userhub
2016-04-05T23:33:55.947419-04 Error - removed last watch
2016-04-05T23:33:55.947473-04 Error - Stream ended (start)
2016-04-05T23:51:20.015907-04 Info - Error: Caught EOF on underlying FLOW

/var/log/transfused.log was empty.

Here’s my pinata diagnose:

OS X: version 10.11.4 (build: 15E65) version v1.11.0-beta6
Running diagnostic tests:
[OK]      docker-cli
[OK]      Moby booted
[OK]      driver.amd64-linux
[OK]      vmnetd
[OK]      osxfs
[OK]      db
[OK]      slirp
[OK]      menubar
[OK]      environment
[OK]      Docker
[OK]      VT-x
Docker logs are being collected into /tmp/20160405-235557.tar.gz.

Also, unlike OP, I don’t have any custom mountpoints on my host mac.

(David Sheets) #6

Could you please run pinata diagnose -u to upload the log archive?

Also, could you please enter the debug console of the VM with screen ~/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/tty and then cat /var/transfused_start.log?

(Tomfrost) #7

I’m being prompted to log in after that screen command – any thoughts?

Login Prompt

I’ve uploaded my logs, bugsnag id is: 4D76F500-A6CA-45D2-B18A-ABFFBF17071E

(David Sheets) #8

Username: root
No password

(Tomfrost) #9


docker:~# cat /var/transfused_start.log
2016-03-29 20:12:11.250 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac
2016-03-29 20:12:11.251 Log mount trigger fired on /Mac, logging to /Mac/Users/tom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-03-30 17:44:08.199 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac
2016-03-30 17:44:08.203 Log mount trigger fired on /Mac, logging to /Mac/Users/tom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-03-30 17:46:28.981 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac
2016-03-30 17:46:28.984 Log mount trigger fired on /Mac, logging to /Mac/Users/tom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-03-31 17:57:05.508 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac
2016-03-31 17:57:05.510 Log mount trigger fired on /Mac, logging to /Mac/Users/tom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-06 03:29:32.342 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac
2016-04-06 03:29:32.344 Log mount trigger fired on /Mac, logging to /Mac/Users/tom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
(Michael Clifford) #10

Providing my info as well:

~ pinata diagnose -u
OS X: version 10.11.4 (build: 15E64a) version v1.11.0-beta6
Running diagnostic tests:
[OK]      docker-cli
[OK]      Moby booted
[OK]      driver.amd64-linux
[OK]      vmnetd
[OK]      osxfs
[OK]      db
[OK]      slirp
[OK]      menubar
[OK]      environment
[OK]      Docker
[OK]      VT-x
Docker logs are being collected into /tmp/20160406-123425.tar.gz.
Your unique id in bugsnag is: D42DC90E-3BCE-4C61-93A6-C271A46292A6
docker:~# cat /var/transfused_start.log
2016-04-02 05:01:43.976 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 05:01:43.977 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-02 05:30:37.845 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 05:30:37.847 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-02 05:38:27.694 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 05:38:27.695 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-02 05:39:13.600 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 05:39:13.601 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-02 06:49:16.113 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 06:49:16.115 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-02 06:49:40.636 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-02 06:49:40.638 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-03 18:24:40.633 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-03 18:24:40.635 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-06 16:10:00.696 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-06 16:10:00.698 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-06 16:11:13.669 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-06 16:11:13.670 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-06 19:01:15.693 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-06 19:01:15.695 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log
2016-04-06 19:17:12.613 mount /bin/fusermount -o allow_other,max_read=32741,subtype=osxfs /Mac 
2016-04-06 19:17:12.615 Log mount trigger fired on /Mac, logging to /Mac/Users/cliffom/Library/Containers/com.docker.docker/Data/com.docker.driver.amd64-linux/log/transfused.log

The /Mac mount point exists on the VM:

docker:~# mount | grep Mac
osxfs on /Mac type fuse.osxfs (rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other,max_read=32741)

I can mount a folder on my Mac’s / via

docker run --rm -it -v /Mac/var:/tmp/test -w /tmp/test alpine /bin/sh

It appears fuse.osxfs is working as intended:

/tmp/test # mount |grep test
osxfs on /tmp/test type fuse.osxfs (rw,nosuid,nodev,relatime,user_id=0,group_id=0,allow_other,max_read=32741)

@tomfrost Would you mind confirming whether or not this is the case on your end?

File access in mounted volumes extremely slow, CPU bound
(Daniel Dunbar) #11

Can anyone comment on how to get more info on the “Socket not connected” message?

(Tomfrost) #12

@cliffom I have the same results to all your tests on my machine. Good catch! So osxfs is there, it’s just not automounting. What’s more, this confirms that the test from the file access performance thread was, in fact, running over osxfs; and so that’s where the speed issue is.

@ddunbar df for me reports “Function not implemented” for my osxfs mounts.

(Michael Clifford) #13

@tomfrost I don’t think auto-mounting /Mac to containers is intended behavior. Containers only mount volumes passed explicitly with -v; Having /Mac in the VM allows you to mount directories outside of /Users and in the Mac volume root / by prefixing them with /Mac. At least that is my understanding.

Perhaps @dsheets can chime in and set us straight. However, as it stands, I don’t think we are having the issues @ddunbar is experiencing.

1 Like
(Daniel Dunbar) #14

That was my understanding as well.

(David Sheets) #15

@ddunbar Socket not connected is concerning to me – it indicates that the VM-side component of osxfs is not running. Can you reproduce it? Does it occur on start-up or only after running a container? Always after running a single container? Do you have a core file in / or /var?

(David Sheets) #16

@cliffom I believe your understanding is correct. We are still developing the appropriate bind mount semantics but, in Beta 6, the special host paths available for bind mounts are /Mac (the whole host), /Users, /Volumes, /tmp, and /private. The mount points only appear in containers when using -v to bind mount into the mount namespace of the container. This gives containers and their operators complete control over the file system namespace of the containerized software.

Unless other people are experiencing Socket not connected or Transport endpoint not connected errors, a new thread should be created to discuss other issues with osxfs.

(David Sheets) #17

@tomfrost The [f]stat[v]fs family of functions (which are necessary for proper df function) are not yet implemented. We have support planned which will export the entire mount table of OS X into the VM but it hasn’t been completed yet. This may also cause issues with database software that expects to be able to successfully execute these syscalls against its data store. Watch the changelog for updates regarding this feature and thanks for using Docker for Mac Beta!

(David Sheets) #18

@ddunbar What is the location and content of your home directory symlink?

(Daniel Dunbar) #19

The link is:

$ ls -lP /Users/ddunbar
lrwxr-xr-x  1 ddunbar  admin  21 Jun 29  2015 /Users/ddunbar -> /Volumes/Data/ddunbar

and /Volumes/Data is an otherwise normal volume (it does use full disk encryption, if that could be related at all).

Does the exact symlink matter if I am completely unable to see any of the mounts inside the VM, or is there some other magic going on when -v is used?

(Frenchben) pinned #20
(Frenchben) unpinned #21
(Daniel Dunbar) #23

I thought this was fixed in the latest beta, but didn’t look closely enough. What has changed is that I now see the directories in the container, but they don’t have any actual files in them.

(David Sheets) #24

Hi Daniel,

Could you please try this again with Beta 8? If it still doesn’t work for you, posting the unique ID from pinata diagnose -u would be helpful as Beta 8 has both better file sharing robustness and better logging to help us track down this issue.

Thank you!

Elasticsearch 1.7.0 fails to start on docker4mac 1.11.1-beta10
(Roman Shtylman) #25

@dsheets trying to follow along with this issue. Are you saying that the df command should now work in beta9? or was that referring to some other command in this thread?