Open johanot opened 7 years ago
Sorry for the slow response. I don't use autofs so I maybe of limited help here. What happens if you send goofys SIGQUIT when it hangs? You may need to write a wrapper script to redirect the output to a file
I have the same issue. autofs configured with debugging enabled. I have scrubbed out my bucket name with the string BUCKET_NAME
I am able to mount it from the command line. my auto map file has: Delivered -fstype=fuse,ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 :goofys#BUCKET_NAME
Nov 16 16:51:56 web6 automount[2121]: handle_packet: type = 3 Nov 16 16:51:56 web6 automount[2121]: handle_packet_missing_indirect: token 296, name Delivered, request pid 2136 Nov 16 16:51:56 web6 automount[2121]: attempting to mount entry /mnt/autofs/storm/Delivered Nov 16 16:51:56 web6 automount[2121]: lookup_mount: lookup(file): looking up Delivered Nov 16 16:51:56 web6 automount[2121]: lookup_mount: lookup(file): Delivered -> -fstype=fuse,ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 :goofys#BUCKET_NAME Nov 16 16:51:56 web6 automount[2121]: parse_mount: parse(sun): expanded entry: -fstype=fuse,ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 :goofys#BUCKET_NAME Nov 16 16:51:56 web6 automount[2121]: parse_mount: parse(sun): gathered options: fstype=fuse,ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 Nov 16 16:51:56 web6 automount[2121]: parse_mount: parse(sun): dequote(":goofys#BUCKET_NAME") -> :goofys#BUCKET_NAME Nov 16 16:51:56 web6 automount[2121]: parse_mount: parse(sun): core of entry: options=fstype=fuse,ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3, loc=:goofys#BUCKET_NAME Nov 16 16:51:56 web6 automount[2121]: sun_mount: parse(sun): mounting root /mnt/autofs/storm, mountpoint Delivered, what goofys#BUCKET_NAME, fstype fuse, options ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 Nov 16 16:51:56 web6 automount[2121]: do_mount: goofys#BUCKET_NAME /mnt/autofs/storm/Delivered type fuse options ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 using module generic Nov 16 16:51:56 web6 automount[2121]: mount_mount: mount(generic): calling mkdir_path /mnt/autofs/storm/Delivered Nov 16 16:51:56 web6 automount[2121]: mount_mount: mount(generic): calling mount -t fuse -s -o ro,nodev,noexec,_netdev,allow_other,--region=us-east-2,--debug_fuse,--debug_s3 goofys#BUCKET_NAME /mnt/autofs/storm/Delivered Nov 16 16:55:44 web6 automount[2121]: >> SIGQUIT: quit Nov 16 16:55:44 web6 automount[2121]: >> PC=0x458353 m=2 sigcode=0 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 0 [idle]: Nov 16 16:55:44 web6 automount[2121]: >> runtime.futex(0xc8bab8, 0x0, 0x7f4242bcdd28, 0x0, 0x7f4200000000, 0x457fe6, 0x3c, 0x0, 0x7f4242bcdd70, 0x40f320, ...) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/sys_linux_amd64.s:426 +0x23 Nov 16 16:55:44 web6 automount[2121]: >> runtime.futexsleep(0xc8bab8, 0x4500000000, 0xdf8475800) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/os_linux.go:62 +0xd7 Nov 16 16:55:44 web6 automount[2121]: >> runtime.notetsleep_internal(0xc8bab8, 0xdf8475800, 0x0) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/lock_futex.go:174 +0xd0 Nov 16 16:55:44 web6 automount[2121]: >> runtime.notetsleep(0xc8bab8, 0xdf8475800, 0x2b30efcfa8d88) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/lock_futex.go:194 +0x56 Nov 16 16:55:44 web6 automount[2121]: >> runtime.sysmon() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/proc.go:3805 +0x135 Nov 16 16:55:44 web6 automount[2121]: >> runtime.mstart1() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/proc.go:1179 +0x11e Nov 16 16:55:44 web6 automount[2121]: >> runtime.mstart() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/proc.go:1149 +0x64 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 1 [semacquire]: Nov 16 16:55:44 web6 automount[2121]: >> sync.runtime_Semacquire(0xc42014476c) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/sema.go:47 +0x34 Nov 16 16:55:44 web6 automount[2121]: >> sync.(WaitGroup).Wait(0xc420144760) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/sync/waitgroup.go:131 +0x7a Nov 16 16:55:44 web6 automount[2121]: >> main.main.func1(0xc4200789a0, 0x0, 0x0) Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/kahing/goofys/main.go:193 +0x675 Nov 16 16:55:44 web6 automount[2121]: >> github.com/urfave/cli.HandleAction(0x8ede20, 0xc4200b32c0, 0xc4200789a0, 0x0, 0x0) Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/urfave/cli/app.go:490 +0xd4 Nov 16 16:55:44 web6 automount[2121]: >> github.com/urfave/cli.(App).Run(0xc4201104e0, 0xc420062680, 0x8, 0x8, 0x0, 0x0) Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/urfave/cli/app.go:264 +0x6ac Nov 16 16:55:44 web6 automount[2121]: >> main.main() Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/kahing/goofys/main.go:246 +0x195 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 17 [syscall, locked to thread]: Nov 16 16:55:44 web6 automount[2121]: >> runtime.goexit() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/asm_amd64.s:2197 +0x1 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 5 [syscall]: Nov 16 16:55:44 web6 automount[2121]: >> os/signal.signal_recv(0x0) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/sigqueue.go:116 +0x104 Nov 16 16:55:44 web6 automount[2121]: >> os/signal.loop() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/os/signal/signal_unix.go:22 +0x22 Nov 16 16:55:44 web6 automount[2121]: >> created by os/signal.init.1 Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/os/signal/signal_unix.go:28 +0x41 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 6 [select, locked to thread]: Nov 16 16:55:44 web6 automount[2121]: >> runtime.gopark(0x9c4df0, 0x0, 0x9a9bea, 0x6, 0x18, 0x2) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/proc.go:271 +0x13a Nov 16 16:55:44 web6 automount[2121]: >> runtime.selectgoImpl(0xc420030f50, 0x0, 0x18) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/select.go:423 +0x1364 Nov 16 16:55:44 web6 automount[2121]: >> runtime.selectgo(0xc420030f50) Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/select.go:238 +0x1c Nov 16 16:55:44 web6 automount[2121]: >> runtime.ensureSigM.func1() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/signal_unix.go:434 +0x2dd Nov 16 16:55:44 web6 automount[2121]: >> runtime.goexit() Nov 16 16:55:44 web6 automount[2121]: >> #011/usr/local/go/src/runtime/asm_amd64.s:2197 +0x1 Nov 16 16:55:44 web6 automount[2121]: >> goroutine 7 [chan receive]: Nov 16 16:55:44 web6 automount[2121]: >> main.waitForSignal.func1(0xc42005c960, 0xc420144760) Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/kahing/goofys/main.go:84 +0x57 Nov 16 16:55:44 web6 automount[2121]: >> created by main.waitForSignal Nov 16 16:55:44 web6 automount[2121]: >> #011/home/khc/Code/go/src/github.com/kahing/goofys/main.go:86 +0x107 Nov 16 16:55:44 web6 automount[2121]: >> rax 0xfffffffffffffffc Nov 16 16:55:44 web6 automount[2121]: >> rbx 0x0 Nov 16 16:55:44 web6 automount[2121]: >> rcx 0xffffffffffffffff Nov 16 16:55:44 web6 automount[2121]: >> rdx 0x0 Nov 16 16:55:44 web6 automount[2121]: >> rdi 0xc8bab8 Nov 16 16:55:44 web6 automount[2121]: >> rsi 0x0 Nov 16 16:55:44 web6 automount[2121]: >> rbp 0x7f4242bcdd38 Nov 16 16:55:44 web6 automount[2121]: >> rsp 0x7f4242bcdcf0 Nov 16 16:55:44 web6 automount[2121]: >> r8 0x0 Nov 16 16:55:44 web6 automount[2121]: >> r9 0x0 Nov 16 16:55:44 web6 automount[2121]: >> r10 0x7f4242bcdd28 Nov 16 16:55:44 web6 automount[2121]: >> r11 0x246 Nov 16 16:55:44 web6 automount[2121]: >> r12 0x7ffe901ba250 Nov 16 16:55:44 web6 automount[2121]: >> r13 0x7f4242bce9c0 Nov 16 16:55:44 web6 automount[2121]: >> r14 0x0 Nov 16 16:55:44 web6 automount[2121]: >> r15 0x3 Nov 16 16:55:44 web6 automount[2121]: >> rip 0x458353 Nov 16 16:55:44 web6 automount[2121]: >> rflags 0x246 Nov 16 16:55:44 web6 automount[2121]: >> cs 0x33 Nov 16 16:55:44 web6 automount[2121]: >> fs 0x0 Nov 16 16:55:44 web6 automount[2121]: >> gs 0x0 Nov 16 16:55:44 web6 automount[2121]: mount(generic): failed to mount goofys#BUCKET_NAME (type fuse) on /mnt/autofs/storm/Delivered Nov 16 16:55:44 web6 automount[2121]: dev_ioctl_send_fail: token = 296 Nov 16 16:55:44 web6 automount[2121]: failed to mount /mnt/autofs/storm/Delivered Nov 16 16:55:44 web6 /usr/bin/goofys[2148]: main.FATAL Mounting file system: Mount: stat /mnt/autofs/storm/Delivered: no such file or directory Nov 16 16:55:44 web6 automount[2121]: handle_packet: type = 3 Nov 16 16:55:44 web6 automount[2121]: handle_packet_missing_indirect: token 297, name Delivered, request pid 2136 Nov 16 16:55:44 web6 automount[2121]: attempting to mount entry /mnt/autofs/storm/Delivered Nov 16 16:55:44 web6 automount[2121]: lookup_mount: lookup(file): looking up Delivered Nov 16 16:55:44 web6 automount[2121]: dev_ioctl_send_fail: token = 297 Nov 16 16:55:44 web6 automount[2121]: failed to mount /mnt/autofs/storm/Delivered Nov 16 16:55:47 web6 automount[2121]: st_expire: state 1 path /mnt/autofs Nov 16 16:55:47 web6 automount[2121]: expire_proc: exp_proc = 140073048012544 path /mnt/autofs Nov 16 16:55:47 web6 automount[2121]: st_expire: state 1 path /mnt/autofs/storm Nov 16 16:55:47 web6 automount[2121]: expire_proc: exp_proc = 140072996521728 path /mnt/autofs/storm Nov 16 16:55:47 web6 automount[2121]: expire_cleanup: got thid 140072996521728 path /mnt/autofs/storm stat 1 Nov 16 16:55:47 web6 automount[2121]: expire_cleanup: sigchld: exp 140072996521728 finished, switching from 2 to 1 Nov 16 16:55:47 web6 automount[2121]: st_ready: st_ready(): state = 2 path /mnt/autofs/storm Nov 16 16:55:47 web6 automount[2121]: 1 submounts remaining in /mnt/autofs Nov 16 16:55:47 web6 automount[2121]: expire_cleanup: got thid 140073048012544 path /mnt/autofs stat 2 Nov 16 16:55:47 web6 automount[2121]: expire_cleanup: sigchld: exp 140073048012544 finished, switching from 2 to 1 Nov 16 16:55:47 web6 automount[2121]: st_ready: st_ready(): state = 2 path /mnt/autofs
hi @kahing, I also working on autofs for mounting s3 bucket automatically. the autofs service running smoothly using s3fs. and it (almost there) also running with goofys. I said almost there because when I tried combined goofys with autofs, I figure out something, and hope this information can make goofys better, things happened are :
But, I have to access it "twice at the first" (e.g using command ls /path/to/mount/point
) to get list of the files on the bucket. I can tell this stuff after I tried mount a bucket into two different path with two different method, which is mount the bucket directly using goofys command and using autofs service. both of them are run foreground with debug enabled.
But first thing first, here is my environment :
And here is the configuration of the autofs (more about autofs configuration for fuse, see here)
auto.master
configuration file :#
# Sample auto.master file
# This is a 'master' automounter map and it has the following format:
# mount-point [map-type[,format]:]map [options]
# For details of the format look at auto.master(5).
#
#/misc /etc/auto.misc
#
# NOTE: mounts done from a hosts map will be mounted with the
# "nosuid" and "nodev" options unless the "suid" and "dev"
# options are explicitly given.
#
#/net -hosts
#
# Include /etc/auto.master.d/*.autofs
# The included files must conform to the format of this file.
#
#+dir:/etc/auto.master.d
#
# Include central master map if it can be found using
# nsswitch sources.
#
# Note that if there are entries for /net or /misc (as
# above) in the included master map any keys that are the
# same will not be seen as the first read key seen takes
# precedence.
#
+auto.master
/- /etc/auto.rcu.goofys --timeout=300
auto.rcu.goofys
configuration file :# user bucket config
# [mount-point] [parameter-or-option-mounting] [tools]:[bucket-name]
/tmp/s3-rcu-alfinhidayat -fstype=fuse,-f,_netdev,allow_other,--uid=1000,-gid=1000,--file-mode=0766,-dir-mode=0766,--cheap,--storage-class=STANDARD,--debug_fuse :goofys#rcu-alfinhidayat
So I open 4 ssh session, the 2 session on the top are process for listing file using ls
command, and the 2 on bottom are mounting process. for debugging the autofs and run it foreground, here is the command (see more here):
automount -vdf
and here is the goofys command that I used :
goofys rcu-alfinhidayat /tmp/s3-rcu-alfinhidayat2 -o rw,-f,allow_other,--uid=1000,-gid=1000,--file-mode=0766,-dir-mode=0766,--cheap,--storage-class=STANDARD,--debug_fuse,dev,suid
the mounting process and the service is running, we go to next phase
ls
commandas you can see, at the phase two, on the "after image" and "re-listing image", the bucket can be accessed as usual just like mount directly using goofys command, but I have to cancel it first since it hangs a moment (I let it for 30 seconds more or less). And if I use s3fs, its running well, I mean I don't need to run list and then cancel the command at the first.
And here is the screencapture and configuration when using s3fs on auto.rcu.goofys file :
/mnt/s3-rcu-alfinhidayat -fstype=fuse,-d,allow_other,uid=33,gid=33,use_cache=/home/alfin/cache/rcu-tmp,nonempty,use_rrs=0,enable_noobj_cache,nodnscache,noua,max_stat_cache_size=150000,multireq_max=8,url=http://s3.amazonaws.com,retries=5,readwrite_timeout=120,connect_timeout=300 :s3fs#rcu-alfinhidayat
I have no idea why, but I hope goofys can do same as s3fs because mainly our system using goofys.
best regards, alfin
@kahing any ideas on this?
We've been able to replicate this as well
Checking the stack trace strace -p PID
strace: Process 79046 attached
futex(0x1461348, FUTEX_WAIT_PRIVATE, 0, NULL
So it seems to wait for something.
I tried to use a minimum script to call the executable with a working behavior. I resulted in /usr/local/bin/goofys2
(use this as fuse prefix):
#!/bin/bash
goofys $@ </dev/null >/dev/null 2>/dev/null &
Removing any of the stream redirections resulted in the same behavior as using the goofys
executable directly. So I suppose the issue is connected to input/output.
It is also interesting that the mount is performed 4-5 times when using the above script (journalctl -u autofs -f
shows 4-5 times successfully mounted and service autofs status
lists 4-5 processes with ids).
UP!
@darkdragon-001 Not sure to follow everything: is using your goofy2s
wrapper making autofs work properly ?
I experimented with the goofy2 script and observed the same behavior: it works with it and the mountpoint is mounted multiple times:
findmnt -t fuse
TARGET SOURCE FSTYPE OPTIONS
/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
└─/goofys/p4m-analytics-test p4m-analytics-test fuse rw,relatime,user_id=0,group_id=0,default_permissions,allow_other
Other infos:
Trying to mount bucket with goofys using autofs, but.. When I try to cd into the mount location, the terminal process hangs and mounting obviosly doesn't work:
goofys --version goofys version 0.0.17-3d40e98b163a797e800550a30e950dc06f7229b1
Trying to access autofs-mounted bucket:
[ec2-user@ip-192-168-1-81 ~]$ cd /data/app ^C^C-bash: cd: /data/app: Interrupted system call
Content of autofs master map (/etc/auto.master)
/data /etc/auto.data --ghost --timeout=10
/etc/auto.data
app -fstype=fuse,ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 :/usr/bin/goofys\#bucket
/var/log/messages output
26 14:17:45 ip-192-168-1-81 automount[29215]: mounted indirect on /data with timeout 300, freq 75 seconds Sep 26 14:17:45 ip-192-168-1-81 automount[29215]: st_ready: st_ready(): state = 0 path /data Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: handle_packet: type = 3 Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: handle_packet_missing_indirect: token 172, name app, request pid 18912 Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: attempting to mount entry /data/app Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: lookup_mount: lookup(file): looking up app Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: lookup_mount: lookup(file): app -> -fstype=fuse,ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 :/usr/bin/goofys#bucket Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: parse_mount: parse(sun): expanded entry: -fstype=fuse,ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 :/usr/bin/goofys#bucket Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: parse_mount: parse(sun): gathered options: fstype=fuse,ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: parse_mount: parse(sun): dequote(":/usr/bin/goofys#bucket") -> :/usr/bin/goofys#bucket Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: parse_mount: parse(sun): core of entry: options=fstype=fuse,ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666, loc=:/usr/bin/goofys#bucket Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: sun_mount: parse(sun): mounting root /data, mountpoint app, what /usr/bin/goofys#bucket, fstype fuse, options ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: do_mount: /usr/bin/goofys#bucket /data/app type fuse options ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 using module generic Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: mount_mount: mount(generic): calling mkdir_path /data/app Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: mount_mount: mount(generic): calling mount -t fuse -s -o ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 /usr/bin/goofys#bucket /data/app Sep 26 14:18:35 ip-192-168-1-81 automount[29215]: spawn_mount: mtab link detected, passing -n to mount Sep 26 14:19:26 ip-192-168-1-81 automount[29215]: st_expire: state 1 path /data Sep 26 14:19:26 ip-192-168-1-81 automount[29215]: expire_proc: exp_proc = 140674273302272 path /data Sep 26 14:19:26 ip-192-168-1-81 automount[29215]: expire_cleanup: got thid 140674273302272 path /data stat 1 Sep 26 14:19:26 ip-192-168-1-81 automount[29215]: expire_cleanup: sigchld: exp 140674273302272 finished, switching from 2 to 1 Sep 26 14:19:26 ip-192-168-1-81 automount[29215]: st_ready: st_ready(): state = 2 path /data
If I stop the autofs-process (which I have to kill -9 by the way), I am perfectly capable of executing:
# mount -t fuse -s -o ro,_netdev,allow_other,--region=eu-central-1,--debug_fuse,--debug_s3,--file-mode=0666 /usr/bin/goofys#bucket /data/app
.. i works without issues. Same does:
# goofys --region=eu-central-1 bucket /data/app
It seems like it might be the combination of autofs and fuse causing the problem? Please help :+1:
P.S. Mounting ro or rw makes no difference. And yes, my AWS Credentials are present in /root/.aws/credentials.