Constant goofys crash

[kangaroo]

I'm getting a consistent crash on every moderate sized upload:

goroutine 28 [running]: 
github.com/kahing/goofys/internal.(*Inode).DeRef(0xc437888ea0, 0x1, 0xc437888ea0) 
        /home/plasma/work/src/github.com/kahing/goofys/internal/handles.go:290 +0x26d 
github.com/kahing/goofys/internal.(*Goofys).ForgetInode(0xc420165ee0, 0xa07340, 0xc45719ff20, 0xc43786d5b0, 0x89c240, 0xc43786d5b0) 
        /home/plasma/work/src/github.com/kahing/goofys/internal/goofys.go:697 +0x79 
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc4203b21e0, 0xc4203a81a0, 0xa07340, 0xc45719ff20, 0x89c240, 0xc43786d5b0) 
        /home/plasma/work/src/github.com/jacobsa/fuse/fuseutil/file_system.go:151 +0x8c4 
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps(0xc4203b21e0, 0xc4203a81a0) 
        /home/plasma/work/src/github.com/jacobsa/fuse/fuseutil/file_system.go:119 +0x11c 
github.com/jacobsa/fuse.Mount.func1(0xa02260, 0xc4203b21e0, 0xc4203a81a0, 0xc420176018) 
        /home/plasma/work/src/github.com/jacobsa/fuse/mount.go:89 +0x3f 
created by github.com/jacobsa/fuse.Mount 
        /home/plasma/work/src/github.com/jacobsa/fuse/mount.go:88 +0x497 

[gaul]

Which operation causes this? Can you reproduce a test case?

[silenceli]

I meet the same issue:

panic: Unknown inode: 2209

goroutine 40 [running]:
github.com/kahing/goofys/internal.(*Goofys).getInodeOrDie(0xc420220680, 0x8a1, 0xc422d3dec0)
	/opt/ml/bin/work/src/github.com/kahing/goofys/internal/goofys.go:421 +0x126
github.com/kahing/goofys/internal.(*Goofys).ForgetInode(0xc420220680, 0xa00a00, 0xc4230111a0, 0xc422d55000, 0x896dc0, 0xc422d55000)
	/opt/ml/bin/work/src/github.com/kahing/goofys/internal/goofys.go:696 +0x58
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc4202a81c0, 0xc42032e820, 0xa00a00, 0xc4230111a0, 0x896dc0, 0xc422d55000)
	/opt/ml/bin/work/src/github.com/jacobsa/fuse/fuseutil/file_system.go:151 +0x8c4
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps(0xc4202a81c0, 0xc42032e820)
	/opt/ml/bin/work/src/github.com/jacobsa/fuse/fuseutil/file_system.go:119 +0x11c
github.com/jacobsa/fuse.Mount.func1(0x9fb920, 0xc4202a81c0, 0xc42032e820, 0xc4202b0028)
	/opt/ml/bin/work/src/github.com/jacobsa/fuse/mount.go:89 +0x3f
created by github.com/jacobsa/fuse.Mount
	/opt/ml/bin/work/src/github.com/jacobsa/fuse/mount.go:88 +0x497

[kahing]

what version is this, could you try master?

[dannykitchen]

Also have this issue on the latest build version

2018/12/07 17:04:52.924861 fuse.DEBUG <-- LookUpInode 4 ecc65405-fe6a-45c4-9b72-7d4f726553cd.jpg
2018/12/07 17:04:52.924946 fuse.DEBUG Op 0x00000415 connection.go:478] -> OK (inode 981)
2018/12/07 17:04:52.925063 fuse.DEBUG Op 0x00000416 connection.go:395] <- ReadDir (inode 4)
2018/12/07 17:04:52.925211 fuse.DEBUG ReadDir 4 pa [977]
panic: invalid offset 977, base=999

goroutine 1165 [running]:
github.com/kahing/goofys/internal.(*DirHandle).ReadDir(0xc4200ab3c0, 0x3d1, 0xc4200ab3c8, 0xc420a3c970, 0x1)
/tmp/go/src/github.com/kahing/goofys/internal/dir.go:342 +0x12ca
github.com/kahing/goofys/internal.(*Goofys).ReadDir(0xc420183930, 0x5604af468540, 0xc420eecd80, 0xc420657b80, 0x0, 0x0)
/tmp/go/src/github.com/kahing/goofys/internal/goofys.go:814 +0x255
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc4203a6b60, 0xc420500750, 0x5604af468540, 0xc420eecd80, 0x5604af376c60, 0xc420657b80)
/tmp/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:181 +0xc87
created by github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps
/tmp/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:121 +0x178

Issue is when there are a lot of files in the bucket

[githubsmartdigit]

+1

[signaleleven]

I also have the "panic: invalid offset", occasionally, while running a find on moderately full directories (can't provide stats right now, but hundreds, not thousands of files, let's say).
It's the issue that @dannykitchen is reporting, probably different than the others in this issue. Perhaps they should be split?

[signaleleven]

Upon further testing:

it happens, not always, but periodically, on directories with more than 1000 files.

/directory/mounted # ls -ltr | wc -l
1282
/directory/mounted # ls -ltr | wc -l
1282
/directory/mounted # ls -ltr | wc -l
986
/directory/mounted # ls -ltr | wc -l
ls: .: Socket not connected
0
/directory/mounted #

The same directory, listed from a container based on ubuntu:18.04 never causes a crash.
Listing it from an alpine container (sharing the mount with ubuntu:18.04) causes the crash of the ubuntu container.

[kahing]

have you tried master?

[signaleleven]

Honestly, I haven't.
I changed a bit the design of the system using it, and now I am not sharing the mountpoint with alpine anymore.
The next time I work on it I'll try to set up a test for it.

[yangqing18]

We are using goofys to mount a S3 bucket so our customer can use FTP client to upload files to S3, but goofys crashes sometimes.
Here is our configuration:

1. goofys is running in a container (centos:centos7.4.1708) with memory limit 2GB. goofys version is 0.19.0-943e017724ea820eb4185419ef3c41d6f921a324
2. S3 bucket has 10TB+ files
3. When we use 50 concurrent FTP clients to upload files, goofys crashe. The errors are as below.
   panic: runtime error: index out of range

goroutine 23491354 [running]:
github.com/kahing/goofys/internal.(*Inode).isDir(...)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/handles.go:151
github.com/kahing/goofys/internal.(*Inode).findInodeFunc.func1(0x1244, 0x863300)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/handles.go:151 +0xaa
sort.Search(0x1245, 0xc430f1c540, 0x15)
/usr/local/go/src/sort/search.go:66 +0x58
github.com/kahing/goofys/internal.(*Inode).insertChildUnlocked(0xc420726630, 0xc42d2fec60)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/handles.go:240 +0x13b
github.com/kahing/goofys/internal.(*Goofys).insertInode(0xc4201d28f0, 0xc420726630, 0xc42d2fec60)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/goofys.go:687 +0x53
github.com/kahing/goofys/internal.(*Goofys).CreateFile(0xc4201d28f0, 0xc89020, 0xc42f75d0e0, 0xc4203ff180, 0x0, 0x0)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/goofys.go:973 +0x138
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc4203b61a0, 0xc42057e0c0, 0xc89020, 0xc42f75d0e0, 0x8ba240, 0xc4203ff180)
/home/khc/Code/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:160 +0x547
created by github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps
/home/khc/Code/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:121 +0x176

Sometimes, the error is:
panic: 6ab02fbd-2981-401d-928b-f6c676a18d7d_staging_instance_25/ftpTest12on.removeName(smallFiles0041356.pdf) but child not found: 22

goroutine 92 [running]:
github.com/kahing/goofys/internal.(*Inode).removeChildUnlocked(0xc420722870, 0xc42df742d0)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/handles.go:203 +0x4dd
github.com/kahing/goofys/internal.(*Inode).removeChild(0xc420722870, 0xc42df742d0)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/handles.go:222 +0x78
github.com/kahing/goofys/internal.(*Goofys).ForgetInode(0xc4201e4750, 0xc89020, 0xc433560de0, 0xc42c529070, 0x8ba340, 0xc42c529070)
/home/khc/Code/go/src/github.com/kahing/goofys/internal/goofys.go:707 +0x10d
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc42039e5c0, 0xc4202a0180, 0xc89020, 0xc433560de0, 0x8ba340, 0xc42c529070)
/home/khc/Code/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:151 +0x931
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps(0xc42039e5c0, 0xc4202a0180)
/home/khc/Code/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:119 +0x11c
github.com/jacobsa/fuse.Mount.func1(0xc830e0, 0xc42039e5c0, 0xc4202a0180, 0xc42000e0a0)
/home/khc/Code/go/src/github.com/jacobsa/fuse/mount.go:90 +0x3f
created by github.com/jacobsa/fuse.Mount
/home/khc/Code/go/src/github.com/jacobsa/fuse/mount.go:89 +0x4e8

[dougstarfish]

I've been running into this a lot lately. It is exacerbated by running parallel scans with multiple threads and I can make it happen regularly in this use case on a relatively large bucket (~25mil files).

I have used master and here's my reproduced traceback. (fuse logging and s3 logging were both turned on, but it doesn't look like they are very helpful)

2019/06/02 22:35:43.049582 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [112. 120]
2019/06/02 22:35:43.049594 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1120. 121]
2019/06/02 22:35:43.049612 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1121. 122]
2019/06/02 22:35:43.049626 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1122. 123]
2019/06/02 22:35:43.049638 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1123. 124]
2019/06/02 22:35:43.049650 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1124. 125]
2019/06/02 22:35:43.049661 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1125. 126]
2019/06/02 22:35:43.049672 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1126. 127]
2019/06/02 22:35:43.049683 fuse.DEBUG <-- ReadDir 15986854860770944332 enron85/farmer-d/discussion_threads [1128. 128]
2019/06/02 22:35:43.049724 fuse.DEBUG Op 0x0016c0b1 connection.go:478] -> OK ()
panic: deref 1 from 0

goroutine 83 [running]:
github.com/kahing/goofys/internal.(*Inode).DeRef(0xc00a085560, 0x1, 0xc000165b58)
/home/doug/go/src/github.com/kahing/goofys/internal/handles.go:292 +0x23c
github.com/kahing/goofys/internal.(*Goofys).ForgetInode(0xc000165ad0, 0xa75180, 0xc0514bbe00, 0xc04698e9b0, 0x0, 0x0)
/home/doug/go/src/github.com/kahing/goofys/internal/goofys.go:718 +0xde
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc000310400, 0xc00009e680, 0xa75180, 0xc0514bbe00, 0x8dff80, 0xc04698e9b0)
/home/doug/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:151 +0x8c4
github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps(0xc000310400, 0xc00009e680)
/home/doug/go/src/github.com/jacobsa/fuse/fuseutil/file_system.go:119 +0x11c
github.com/jacobsa/fuse.Mount.func1(0xa70020, 0xc000310400, 0xc00009e680, 0xc000280038)
/home/doug/go/src/github.com/jacobsa/fuse/mount.go:89 +0x3f
created by github.com/jacobsa/fuse.Mount
/home/doug/go/src/github.com/jacobsa/fuse/mount.go:88 +0x492

[dougstarfish]

My theory is that DeRef is being called in parallel threads for the same inode when there is a lot of parallel activity going on. I'm guessing ForgetInode is being called twice from Fuse somehow? I have hacked around it for my testing (since the S3 is static) by changing DeRef to issue a warning when the link count would go < 0 on a double deref, set stale and count to 0, and return instead of doing a panic. I'm not sure what would happen if the bucket was actually being written during this. Probably nothing good, but it's good for my test use case on a readonly mount.

[dougstarfish]

I seem to still get these (2019-11-05) in mainline master. 0.22.0
2019/11/05 15:34:45.842798 main.ERROR stacktrace from panic: deref 4 from 2
goroutine 55 [running]:
runtime/debug.Stack(0xc0000bfcd8, 0xce7b40, 0xc1051dc290)
/usr/lib/golang/src/runtime/debug/stack.go:24 +0xa7
github.com/kahing/goofys/api/common.LogPanic(0xc0000bfeb8)
/home/doug/go/src/github.com/kahing/goofys/api/common/panic_logger.go:32 +0x6e
panic(0xce7b40, 0xc1051dc290)
/usr/lib/golang/src/runtime/panic.go:513 +0x1b9
github.com/kahing/goofys/internal.(*Inode).DeRef(0xc0cdab2510, 0x4, 0xc0694d5d08)
/home/doug/go/src/github.com/kahing/goofys/internal/handles.go:249 +0x23c
github.com/kahing/goofys/internal.(*Goofys).ForgetInode(0xc0002959a0, 0x1020240, 0xc114be4ff0, 0xc111f30370, 0x0, 0x0)
/home/doug/go/src/github.com/kahing/goofys/internal/goofys.go:729 +0x9e
github.com/kahing/goofys/api/common.FusePanicLogger.ForgetInode(0x102c400, 0xc0002959a0, 0x1020240, 0xc114be4ff0, 0xc111f30370, 0x0, 0x0)
/home/doug/go/src/github.com/kahing/goofys/api/common/panic_logger.go:57 +0x81
github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).handleOp(0xc0000d8420, 0xc0000a52b0, 0x1020240, 0xc114be4ff0, 0xcbe860, 0xc111f30370)
/home/doug/go/src/github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/fuseutil/file_system.go:151 +0x8c4
github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/fuseutil.(*fileSystemServer).ServeOps(0xc0000d8420, 0xc0000a52b0)
/home/doug/go/src/github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/fuseutil/file_system.go:119 +0x11c
github.com/kahing/goofys/vendor/github.com/jacobsa/fuse.Mount.func1(0x1015ac0, 0xc0000d8420, 0xc0000a52b0, 0xc0000aa048)
/home/doug/go/src/github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/mount.go:89 +0x3f
created by github.com/kahing/goofys/vendor/github.com/jacobsa/fuse.Mount
/home/doug/go/src/github.com/kahing/goofys/vendor/github.com/jacobsa/fuse/mount.go:88 +0x492

But, if I run goofys -f, it doesn't seem to be fatal to the process and I can still run ls operations.