rjeczalik / notify

File system event notification library on steroids.
MIT License
906 stars 128 forks source link

kqueue: failed to read events: "interrupted system call" #49

Closed rjeczalik closed 9 years ago

rjeczalik commented 9 years ago

Just FYI @pblaszczyk, probably it's just broken for OS X.

Steps to reproduce (sorry, no test yet).

~ $ go install github.com/rjeczalik/fs/cmd/mktree github.com/rjeczalik/fs/cmd/gotree
~ $ go install github.com/rjeczalik/notify/cmd/notify
~ $ # run in different terminal: notify $HOME/...
~ $ mkdir -p /tmp/1/2/3
~ $ touch /tmp/1/2.txt                                                                                                                            
~ $ touch /tmp/1/2/3.txt                                                                                                                          
~ $ touch /tmp/1/2/3/.txt
~ $ gotree /tmp/1 | mktree -o .

Panics with:

panic: permission denied

goroutine 20 [running]:
runtime.panic(0xe20a0, 0xd)
        /usr/local/gvm/gos/go1.3.3/src/pkg/runtime/panic.c:279 +0xf5
github.com/rjeczalik/notify.func·009(0x22081e94f0, 0x20824bd60, 0x0, 0x0)
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:143 +0x244
github.com/rjeczalik/notify.(*kqueue).walk(0x2081fc330, 0x208216100, 0x3a, 0x22083a0f28, 0x0, 0x0)
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:299 +0x155
github.com/rjeczalik/notify.(*kqueue).monitor(0x2081fc330)
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:149 +0x911
created by github.com/rjeczalik/notify.(*kqueue).Dispatch
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:376 +0x41

goroutine 16 [chan receive]:
main.main()
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/cmd/notify/main.go:49 +0x1b0

goroutine 19 [finalizer wait, 1 minutes]:
runtime.park(0x14ef0, 0x19b810, 0x19ab89)
        /usr/local/gvm/gos/go1.3.3/src/pkg/runtime/proc.c:1369 +0x89
runtime.parkunlock(0x19b810, 0x19ab89)
        /usr/local/gvm/gos/go1.3.3/src/pkg/runtime/proc.c:1385 +0x3b
runfinq()
        /usr/local/gvm/gos/go1.3.3/src/pkg/runtime/mgc0.c:2644 +0xcf
runtime.goexit()
        /usr/local/gvm/gos/go1.3.3/src/pkg/runtime/proc.c:1445

goroutine 21 [select, 1 minutes]:
github.com/rjeczalik/notify.(*Tree).loopdispatch(0x2081f2280, 0x2081eb200)
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/tree.go:179 +0x478
created by github.com/rjeczalik/notify.NewTree
        /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/tree.go:217 +0x1c6
rjeczalik commented 9 years ago

Recent acceptance test on OS X:

$ go test -tags kqueue -v -run TestNotifyExample
=== RUN TestNotifyExample
3
3
3
3
3
3
3
3
3
kqueue: failed to read events: "interrupted system call"
3
kqueue: failed to read events: "bad file descriptor"
3
kqueue: failed to read events: "bad file descriptor"
3

(...)

kqueue: failed to read events: "bad file descriptor"
3
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x0 pc=0x6c0ca]

goroutine 7 [running]:
github.com/rjeczalik/notify.(*kqueue).monitor(0x208378300)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:123 +0x25a
created by github.com/rjeczalik/notify.newWatcher
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:28 +0x1cb

goroutine 1 [chan receive]:
testing.RunTests(0x219488, 0x2ad1a0, 0xf, 0xf, 0x2af201)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:576 +0x58e
testing.(*M).Run(0x2083600f0, 0x2b5be0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:485 +0x6c
main.main()
    github.com/rjeczalik/notify/_test/_testmain.go:80 +0x1d5

goroutine 5 [runnable]:
syscall.Syscall(0x89, 0x208362600, 0x0, 0x0, 0xffffffffffffffff, 0x0, 0x42)
    /Users/rjeczalik/.gvm/gos/go1.4/src/syscall/asm_darwin_amd64.s:20 +0x5
syscall.Rmdir(0x208362180, 0x5a, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/syscall/zsyscall_darwin_amd64.go:1047 +0x91
os.Remove(0x208362180, 0x5a, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/file_unix.go:270 +0x9f
os.RemoveAll(0x208362180, 0x5a, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/path.go:68 +0x5b
os.RemoveAll(0x2083608c0, 0x4f, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/path.go:102 +0x45f
os.RemoveAll(0x208360370, 0x4b, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/path.go:102 +0x45f
github.com/rjeczalik/notify.(*W).Close(0x208360410, 0x0, 0x0)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/testing_test.go:266 +0x1da
github.com/rjeczalik/notify.(*N).Close(0x20833c000, 0x0, 0x0)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/testing_test.go:612 +0x3e
github.com/rjeczalik/notify.TestNotifyExample(0x20837c000)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/notify_test.go:67 +0x100c
testing.tRunner(0x20837c000, 0x2ad200)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:447 +0xbf
created by testing.RunTests
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:555 +0xa8b

3 above is value of *(kqueue).fd - it came from here:

iff --git a/watcher_kqueue.go b/watcher_kqueue.go
index f01600b..3db60ff 100644
--- a/watcher_kqueue.go
+++ b/watcher_kqueue.go
@@ -119,6 +119,7 @@ func (k *kqueue) monitor() {
                        return
                default:
                }
+               fmt.Println(*k.fd)
                n, err := syscall.Kevent(*k.fd, nil, kevn[:], nil)
                if err != nil {
                        fmt.Fprintf(os.Stderr, "kqueue: failed to read events: %q\n", err)
ghost commented 9 years ago

If you could attempt to reproduce it on:

diff --git a/watcher_kqueue.go b/watcher_kqueue.go
index f01600b..23c54e5 100644
--- a/watcher_kqueue.go
+++ b/watcher_kqueue.go
@@ -92,6 +92,7 @@ func unmask(o uint32, w Event) (e Event) {
 // del closes fd for `watched` and removes it from internal cache of monitored
 // files/directories.
 func (k *kqueue) del(w *watched) {
+       fmt.Fprintln(os.Stderr, "deleted fd:", w.fd)
        syscall.Close(w.fd)
        delete(k.idLkp, w.fd)
        delete(k.pthLkp, w.p)
@@ -215,6 +216,7 @@ func (k *kqueue) init() error {
        if err != nil {
                return err
        }
+       fmt.Fprintln(os.Stderr, "kqueue fd:", fd)
        k.fd = &fd
        return nil
 }
@@ -254,6 +256,7 @@ func (k *kqueue) singlewatch(p string, e Event, direct bool,
                if err != nil {
                        return err
                }
+               fmt.Fprintln(os.Stderr, "added fd:", fd)
                w = &watched{fd: fd, p: p, fi: fi}
        }
        if direct {

or I'll try later on travis..

rjeczalik commented 9 years ago
$ go test -tags kqueue -v -run TestNotifyExample
=== RUN TestNotifyExample
kqueue fd: 3
added fd: 4
added fd: 5
added fd: 6
added fd: 7
added fd: 8
added fd: 9
added fd: 10
added fd: 11
added fd: 12
added fd: 13
added fd: 14
added fd: 15
added fd: 16
added fd: 17
added fd: 18
added fd: 19
added fd: 20
added fd: 21
added fd: 22
deleted fd: 13
deleted fd: 15
deleted fd: 16
deleted fd: 18
deleted fd: 19
deleted fd: 20
deleted fd: 21
deleted fd: 22
deleted fd: 12
added fd: 12
added fd: 13
added fd: 15
added fd: 16
added fd: 18
added fd: 19
added fd: 20
added fd: 21
added fd: 22
added fd: 23
added fd: 24
3
added fd: 25
added fd: 26
added fd: 27
3
3
added fd: 28
3
added fd: 29
3
deleted fd: 25
3
deleted fd: 5
deleted fd: 7
deleted fd: 9
deleted fd: 11
deleted fd: 4
3
added fd: 4
3
deleted fd: 26
3
kqueue: failed to read events: "interrupted system call"
3
kqueue: failed to read events: "bad file descriptor"
3

(...)

kqueue: failed to read events: "bad file descriptor"
3
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x0 pc=0x6c28a]

goroutine 7 [running]:
github.com/rjeczalik/notify.(*kqueue).monitor(0x208370300)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:124 +0x25a
created by github.com/rjeczalik/notify.newWatcher
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/watcher_kqueue.go:28 +0x1cb

goroutine 1 [chan receive]:
testing.RunTests(0x219ac8, 0x2ae1a0, 0xf, 0xf, 0x2b0201)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:576 +0x58e
testing.(*M).Run(0x2083580f0, 0x2b6be0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:485 +0x6c
main.main()
    github.com/rjeczalik/notify/_test/_testmain.go:80 +0x1d5

goroutine 5 [runnable]:
syscall.Syscall6(0x158, 0x3, 0x208381000, 0x1000, 0x20839b768, 0x0, 0x0, 0x50, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/syscall/asm_darwin_amd64.s:44 +0x5
syscall.Getdirentries(0x3, 0x208381000, 0x1000, 0x1000, 0x20839b768, 0x14a980, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/syscall/zsyscall_darwin_amd64.go:569 +0x93
syscall.ReadDirent(0x3, 0x208381000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/syscall/syscall_bsd.go:71 +0x7a
os.(*File).readdirnames(0x208354128, 0x64, 0x208342700, 0x0, 0x64, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/dir_unix.go:39 +0x221
os.(*File).Readdirnames(0x208354128, 0x64, 0x0, 0x0, 0x0, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/doc.go:134 +0x9e
os.RemoveAll(0x208358370, 0x4b, 0x0, 0x0)
    /Users/rjeczalik/.gvm/gos/go1.4/src/os/path.go:100 +0x358
github.com/rjeczalik/notify.(*W).Close(0x208358410, 0x0, 0x0)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/testing_test.go:266 +0x1da
github.com/rjeczalik/notify.(*N).Close(0x20833c000, 0x0, 0x0)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/testing_test.go:612 +0x3e
github.com/rjeczalik/notify.TestNotifyExample(0x208374000)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/notify_test.go:67 +0x100c
testing.tRunner(0x208374000, 0x2ae200)
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:447 +0xbf
created by testing.RunTests
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:555 +0xa8b

goroutine 6 [chan receive]:
testing.func·007()
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:559 +0x5f
created by testing.RunTests
    /Users/rjeczalik/.gvm/gos/go1.4/src/testing/testing.go:560 +0xb9b

goroutine 8 [select]:
github.com/rjeczalik/notify.(*BigTree).loopdispatch(0x20835a300, 0x20835a120)
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/bigtree.go:71 +0x44d
created by github.com/rjeczalik/notify.NewTree
    /Users/rjeczalik/Workspace/src/github.com/rjeczalik/notify/bigtree.go:107 +0x23e
exit status 2
FAIL    github.com/rjeczalik/notify 0.596s
ghost commented 9 years ago

Ok.. In this case I have to admit that it's sad.. Life is brutal.. I'll look at it as soon as I'll get into travis based development mood..

rjeczalik commented 9 years ago

fd8811f3668f7d1b7

rjeczalik commented 9 years ago

https://travis-ci.org/rjeczalik/notify/builds/47973996

@pblaszczyk Good job sir! Fancy a kudo? XD