search

cespare / reflex

Run a command when files change
MIT License
3.39k stars 136 forks source link

Reflex using 100% CPU #44

Closed mikejquinn closed 6 years ago

mikejquinn commented 7 years ago

This has happened to me a few times on OSX. I'm using the latest reflex and Go 1.9.

I'm not sure yet how to reproduce but I'll update if I get more information. I've pasted a goroutine dump below.

The config file is just watching resource files and calling make.

-r '^resources/assets/.*\.(coffee|js)$' -- make js
-r '^resources/assets/.*\.(less|css)$' -- make css

Goroutine dump:

PC=0x1056bd3 m=2 sigcode=0

goroutine 0 [idle]:
runtime.mach_semaphore_timedwait(0x3c00001e03, 0x0, 0x70000f831cf4, 0x3c, 0x0, 0xc420000900, 0x70000f831d28, 0x1051173, 0xdf8475800, 0x0, ...)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/sys_darwin_amd64.s:455 +0x13
runtime.semasleep1(0xdf8475800, 0x0)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/os_darwin.go:402 +0xdf
runtime.semasleep.func1()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/os_darwin.go:432 +0x33
runtime.systemstack(0x70000f831d50)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/asm_amd64.s:360 +0xab
runtime.semasleep(0xdf8475800, 0x1033b73)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/os_darwin.go:431 +0x44
runtime.notetsleep_internal(0x11f0b18, 0xdf8475800, 0xc420000900, 0x742c47f3603, 0xc400000014)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/lock_sema.go:218 +0x112
runtime.notetsleep(0x11f0b18, 0xdf8475800, 0x7188aae1b01)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/lock_sema.go:269 +0x75
runtime.sysmon()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/proc.go:3866 +0x14d
runtime.mstart1()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/proc.go:1172 +0x11e
runtime.mstart()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/proc.go:1142 +0x64

goroutine 1 [chan receive]:
main.main()
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:201 +0x8ff

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/sigqueue.go:131 +0xa7
os/signal.loop()
    /usr/local/Cellar/go/1.9/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.0
    /usr/local/Cellar/go/1.9/libexec/src/os/signal/signal_unix.go:28 +0x41

goroutine 6 [select, locked to thread]:
runtime.gopark(0x11473a0, 0x0, 0x113e929, 0x6, 0x18, 0x1)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/proc.go:277 +0x12c
runtime.selectgo(0xc420046f50, 0xc4200244e0)
    /usr/local/Cellar/go/1.9/libexec/src/runtime/select.go:395 +0x1138
runtime.ensureSigM.func1()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/signal_unix.go:511 +0x1fe
runtime.goexit()
    /usr/local/Cellar/go/1.9/libexec/src/runtime/asm_amd64.s:2337 +0x1

goroutine 7 [chan receive]:
main.main.func1(0xc42006a540)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:175 +0x4b
created by main.main
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:174 +0x55b

goroutine 8 [syscall]:
syscall.Syscall6(0x16b, 0x3, 0x0, 0x0, 0xc42005fe88, 0xa, 0x120ede0, 0x0, 0x0, 0x0)
    /usr/local/Cellar/go/1.9/libexec/src/syscall/asm_darwin_amd64.s:41 +0x5
github.com/cespare/reflex/vendor/golang.org/x/sys/unix.kevent(0x3, 0x0, 0x0, 0xc42005fe88, 0xa, 0x120ede0, 0x0, 0x0, 0x0)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/vendor/golang.org/x/sys/unix/zsyscall_darwin_amd64.go:207 +0x83
github.com/cespare/reflex/vendor/golang.org/x/sys/unix.Kevent(0x3, 0x0, 0x0, 0x0, 0xc42005fe88, 0xa, 0xa, 0x120ede0, 0x0, 0x0, ...)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/vendor/golang.org/x/sys/unix/syscall_bsd.go:448 +0x71
github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify.read(0x3, 0xc42005fe88, 0xa, 0xa, 0x120ede0, 0xc42005fe88, 0x0, 0xa, 0x0, 0x0)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify/kqueue.go:493 +0x78
github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify.(*Watcher).readEvents(0xc42006a600)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify/kqueue.go:284 +0x572
created by github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify.NewWatcher
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/vendor/github.com/fsnotify/fsnotify/kqueue.go:62 +0x293

goroutine 9 [select]:
main.watch(0x113e2d8, 0x1, 0xc42006a600, 0xc4200246c0, 0xc420024720, 0xc42004e7e0, 0x2, 0x2)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/watch.go:23 +0x2b0
created by main.main
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:193 +0x7d2

goroutine 10 [chan receive]:
main.broadcast(0xc42004e800, 0x2, 0x2, 0xc4200246c0)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:205 +0xa0
created by main.main
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:194 +0x818

goroutine 11 [chan receive]:
main.printOutput(0xc42006a060, 0x11da520, 0xc42000e018)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/print.go:65 +0xa7
created by main.main
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/main.go:195 +0x854

goroutine 12 [chan receive]:
main.(*Reflex).filterMatching(0xc4200a0a00, 0xc420024840, 0xc420024780)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:130 +0x4e
created by main.(*Reflex).Start
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:298 +0x9d

goroutine 13 [chan receive]:
main.(*Reflex).batch(0xc4200a0a00, 0xc4200248a0, 0xc420024840)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:156 +0x292
created by main.(*Reflex).Start
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:299 +0xd3

goroutine 14 [chan receive]:
main.(*Reflex).runEach(0xc4200a0a00, 0xc4200248a0)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:184 +0x4b
created by main.(*Reflex).Start
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:300 +0xff

goroutine 15 [chan receive]:
main.(*Reflex).filterMatching(0xc4200a0be0, 0xc420024900, 0xc4200247e0)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:130 +0x4e
created by main.(*Reflex).Start

[gumtwo] Fix tests
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:298 +0x9d

goroutine 16 [chan receive]:
main.(*Reflex).batch(0xc4200a0be0, 0xc420024960, 0xc420024900)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:156 +0x292
created by main.(*Reflex).Start
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:299 +0xd3

goroutine 18 [chan receive]:
main.(*Reflex).runEach(0xc4200a0be0, 0xc420024960)
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:184 +0x4b
created by main.(*Reflex).Start
    /Users/mikeq/dev/go/src/github.com/cespare/reflex/reflex.go:300 +0xff

rax    0xe
rbx    0x3c
rcx    0x70000f831cc8
rdx    0x0
rdi    0x1e03
rsi    0x3c
rbp    0x70000f831d00
rsp    0x70000f831cc8
r8     0x70000f831dc0
r9     0x6d
r10    0x603d27dc
r11    0x202
r12    0x6029408d5610
r13    0xb03
r14    0x102cf10
r15    0x1400000
rip    0x1056bd3
rflags 0x202
cs     0x7
fs     0x0
gs     0x0
XertroV commented 7 years ago

Also having this issue; -s doesn't seem to matter, and if I omit -s the CPU doesn't pin at 100% until there's a change in the file, then after running the script it pins.

cespare commented 7 years ago

Sorry for the trouble here.

I'm not sure what the problem is -- a quick browse through the goroutine dump doesn't show anything unexpected.

I updated the vendored fsnotify library in case it was a fixed bug there.

If it's not fixed, I'm going to need some hints about how to reproduce. Thanks.

cespare commented 6 years ago

I think this should be fixed now, thanks to @hartshorne.

XertroV commented 6 years ago

Thanks! Will let you know if I can still replicate after updating.

XertroV commented 6 years ago

@cespare - Just wanted to note that this is fixed for me - thanks again!