Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Force launchd plist file to be reloaded when launching watchman #358

Closed
flegall opened this issue Sep 13, 2016 · 31 comments
Closed

Force launchd plist file to be reloaded when launching watchman #358

flegall opened this issue Sep 13, 2016 · 31 comments

Comments

@flegall
Copy link

flegall commented Sep 13, 2016

Hi,

I'm facing a bug with watchman.
Whenever I'm starting watchman and sending a command (such as watchman watch-list or event watchman version or creating a trigger, it's getting stuck.
watchman --help & watchman -v work though.

I've been using watchman for months without troubles.
Yesterday I've enabled filevault on my mac and I upgraded watchman to 4.7.0 using brew.
I've reinstalled 4.6.0 from the sources, I'm observing the same problem.

Any advices on how I could provide you more info / logs on this issue ?

Regards,

Florent

@Bhullnatik
Copy link

I solved it by deleting the <PREFIX>/var/run/watchman/<USER>-state folder (If you installed it with Homebrew, it should be /usr/local/var/run/watchman/).

@flegall
Copy link
Author

flegall commented Sep 13, 2016

Thx! Works like a charm.

@flegall flegall closed this as completed Sep 13, 2016
@flegall
Copy link
Author

flegall commented Sep 13, 2016

Reopening, leaving it to watchman maintainers to decide if it's a bug or not...

@flegall flegall reopened this Sep 13, 2016
@wez
Copy link
Contributor

wez commented Sep 13, 2016

Unfortunately, removing the state dir deleted any logs that we could have used to figure this out, so we have no idea what happened. I'm going to close this because there isn't anything to go on. If this happens for anyone else, please attach the log file from the state dir and we can start troubleshooting from there.

@wez wez closed this as completed Sep 13, 2016
@roefunc
Copy link

roefunc commented Sep 14, 2016

I hit this yesterday with our React Native project - start-packager was hanging and I narrowed it down to watchman. Moving the state dir fixed the problem. If it helps, I'd been changing the system time into the future and back again to test something when the problem started happening, but I have no idea if that's actually connected.
From the logs I see a lot of these:
Terminating due to signal 15 Terminated generated by pid=1 uid=0. (0x0) 0 watchman 0x0000000106a5fcd9 crash_handler + 345 1 libsystem_platform.dylib 0x00007fff980d852a _sigtramp + 26 2 ??? 0x00007fff6827b5c8 0x0 + 140734940820936 3 watchman 0x0000000106a7046d run_service + 695 4 watchman 0x0000000106a6f8ad main + 401 5 libdyld.dylib 0x00007fff97f6e5ad start + 1 6 ??? 0x0000000000000007 0x0 + 7
Logs on request

@wez
Copy link
Contributor

wez commented Sep 14, 2016

@roefunc yes, please provide the logs as I asked in my prior comment!

The excerpt that you included is just how a shutdown request from launchd (pid=1) manifests, so it doesn't tell us anything about why watchman was stopped.

It will probably also be useful for you to open Console.app and filter by watchman to see if there is anything else interesting happening there.

@chriskrycho
Copy link

chriskrycho commented Sep 14, 2016

This is happening for me (in the context of Ember CLI—see the issue referenced directly above this comment on GitHub); I've attached logs below. Curiously, as you'll note, it's reporting Watchman 4.6.0 in the logs even though I have 4.7.0 installed.

There are no messages from watchman in my console logs.

Happy to provide any other info you need as well.

Running:

  • software:
    • watchman 4.7.0, bottled from Homebrew
    • macOS 10.12 (16A320)
  • hardware (just in case):
    • 5K iMac late 2015
    • 5GHz i7
    • 64 GB RAM
    • AMD Radeon R9 M395 2048 M

log data from /usr/local/var/run/watchman/chris-state/log (fair warning: 190 lines)

2016-07-12T08:52:26,426: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-12T08:52:26,426: [listener] failed to parse json from /usr/local/var/run/watchman/chris-state/state: unable to open /usr/local/var/run/watchman/chris-state/state: No such file or directory
2016-07-12T08:52:26,426: [listener] file limit is 256 kern.maxfilesperproc=50000
2016-07-12T08:52:26,426: [listener] raised file limit to 50000
2016-07-12T08:52:26,427: [listener] Using socket from launchd as listening socket
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x00000001013f0cd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fff8e90e52a _sigtramp + 26
2   ???                                 0x000000000000ffff 0x0 + 65535
3   watchman                            0x000000010140146d run_service + 695
4   watchman                            0x00000001014008ad main + 401
5   libdyld.dylib                       0x00007fff8e9ae5ad start + 1
6   ???                                 0x0000000000000007 0x0 + 7
2016-07-12T08:52:26,449: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-12T08:52:26,449: [listener] failed to parse json from /usr/local/var/run/watchman/chris-state/state: unable to open /usr/local/var/run/watchman/chris-state/state: No such file or directory
2016-07-12T08:52:26,449: [listener] file limit is 256 kern.maxfilesperproc=50000
2016-07-12T08:52:26,449: [listener] raised file limit to 50000
2016-07-12T08:52:26,449: [listener] Using socket from launchd as listening socket
2016-07-12T08:52:26,508: [client=0x7f8de1700620:stm=0x7f8de1700160] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-07-12T08:52:26,508: [client=0x7f8de1700620:stm=0x7f8de1700160] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-07-12T08:52:27,052: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 451, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1468327946.5096681, "pid": 85241, "description": "full-crawl", "ru_msgrcv": 5, "ru_majflt": 1, "ru_msgsnd": 1, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.297983, "elapsed_time": 0.54326600000000003, "ru_idrss": 0, "user_time": 0.120048, "ru_maxrss": 29110272, "ru_inblock": 1085, "ru_minflt": 7106, "ru_nswap": 0, "ru_oublock": 121, "ru_nsignals": 0, "ru_nvcsw": 1088}
2016-07-12T08:52:27,052: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-07-12T20:42:07,374: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-12T20:42:07,382: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-07-12T20:42:07,383: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-07-12T20:42:07,398: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-07-12T20:42:07,398: [listener] raised file limit to 50000
2016-07-12T20:42:07,403: [listener] Using socket from launchd as listening socket
2016-07-12T20:42:08,394: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 3958, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1468370527.399019, "pid": 2907, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.31564900000000001, "elapsed_time": 0.99528499999999998, "ru_idrss": 0, "user_time": 0.180038, "ru_maxrss": 29093888, "ru_inblock": 2027, "ru_minflt": 7101, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 120}
2016-07-12T20:42:08,394: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/sshpk-sign) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/sshpk-verify) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/strip-json-comments) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/tap-parser) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/testem) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/uglifyjs) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/user-home) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/uuid) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/which) errno=2 tlen=-1
2016-07-14T15:39:38,890: [io /Users/chris/dev/olo/mobile-web] readlink(/Users/chris/dev/olo/mobile-web/node_modules/.bin/window-size) errno=2 tlen=-1
2016-07-14T15:41:21,130: [io /Users/chris/dev/olo/mobile-web] getattrlist(/Users/chris/dev/olo/mobile-web/node_modules/.staging/tweetnacl-8cb870e4/package.json.297799941) failed: No such file or directory
2016-07-19T15:26:34,891: [io /Users/chris/dev/olo/mobile-web] getattrlist(/Users/chris/dev/olo/mobile-web/.git/next-index-76223.lock) failed: No such file or directory
2016-07-20T15:32:03,102: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-20T15:32:03,104: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-07-20T15:32:03,104: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-07-20T15:32:03,110: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-07-20T15:32:03,110: [listener] raised file limit to 50000
2016-07-20T15:32:03,114: [listener] Using socket from launchd as listening socket
2016-07-20T15:32:03,888: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 3111, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1469043123.1104381, "pid": 3459, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.29714499999999999, "elapsed_time": 0.77824000000000004, "ru_idrss": 0, "user_time": 0.17141899999999999, "ru_maxrss": 28446720, "ru_inblock": 1307, "ru_minflt": 6943, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 849}
2016-07-20T15:32:03,888: [io /Users/chris/dev/olo/mobile-web] crawl complete
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x0000000102285cd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fff9216352a _sigtramp + 26
2   ???                                 0x000000000000ffff 0x0 + 65535
3   watchman                            0x000000010229646d run_service + 695
4   watchman                            0x00000001022958ad main + 401
5   libdyld.dylib                       0x00007fff922035ad start + 1
6   ???                                 0x0000000000000007 0x0 + 7
2016-07-20T18:14:14,312: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-20T18:14:14,313: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-07-20T18:14:14,313: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-07-20T18:14:14,317: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-07-20T18:14:14,317: [listener] raised file limit to 50000
2016-07-20T18:14:14,317: [listener] Using socket from launchd as listening socket
2016-07-20T18:14:15,574: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 4776, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1469052854.317081, "pid": 2686, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.37363200000000002, "elapsed_time": 1.2568980000000001, "ru_idrss": 0, "user_time": 0.186781, "ru_maxrss": 28442624, "ru_inblock": 1997, "ru_minflt": 6942, "ru_nswap": 0, "ru_oublock": 10, "ru_nsignals": 0, "ru_nvcsw": 2020}
2016-07-20T18:14:15,574: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-07-22T11:16:07,153: [client=0x7ff8886969e0:stm=0x7ff888694270] path /Users/chris/dev/personal/test/my-fun-foo-test is on filesystem type hfs
2016-07-22T11:16:07,154: [client=0x7ff8886969e0:stm=0x7ff888694270] root /Users/chris/dev/personal/test/my-fun-foo-test using watcher mechanism fsevents (auto was requested)
2016-07-22T11:16:07,154: [client=0x7ff8889333b0:stm=0x7ff8883f7e20] path /Users/chris/dev/personal/test/my-fun-foo-test is on filesystem type hfs
2016-07-22T11:16:07,154: [client=0x7ff8889333b0:stm=0x7ff8883f7e20] root /Users/chris/dev/personal/test/my-fun-foo-test using watcher mechanism fsevents (auto was requested)
2016-07-22T11:16:07,798: [io /Users/chris/dev/personal/test/my-fun-foo-test] PERF: {"ru_nivcsw": 1736, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/personal/test/my-fun-foo-test", "recrawl_count": 0, "number": 2, "watcher": "fsevents"}}, "start_time": 1469200567.1546309, "pid": 2686, "description": "full-crawl", "ru_msgrcv": 3, "ru_majflt": 0, "ru_msgsnd": 2, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.39335199999999998, "elapsed_time": 0.64395899999999995, "ru_idrss": 0, "user_time": 0.19412599999999999, "ru_maxrss": 45617152, "ru_inblock": 360, "ru_minflt": 11656, "ru_nswap": 0, "ru_oublock": 2, "ru_nsignals": 0, "ru_nvcsw": 362}
2016-07-22T11:16:07,798: [io /Users/chris/dev/personal/test/my-fun-foo-test] crawl complete
2016-07-25T16:26:38,648: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-07-25T16:26:38,653: [listener] path /Users/chris/dev/personal/test/my-fun-foo-test is on filesystem type hfs
2016-07-25T16:26:38,653: [listener] root /Users/chris/dev/personal/test/my-fun-foo-test using watcher mechanism fsevents (auto was requested)
2016-07-25T16:26:38,666: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-07-25T16:26:38,666: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-07-25T16:26:38,672: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-07-25T16:26:38,672: [listener] raised file limit to 50000
2016-07-25T16:26:38,672: [listener] Using socket from launchd as listening socket
2016-07-25T16:26:39,451: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 13630, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 2, "watcher": "fsevents"}}, "start_time": 1469478398.6726379, "pid": 2572, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 0, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.52303500000000003, "elapsed_time": 0.77861199999999997, "ru_idrss": 0, "user_time": 0.28437499999999999, "ru_maxrss": 45899776, "ru_inblock": 3262, "ru_minflt": 11206, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 2110}
2016-07-25T16:26:39,451: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-07-25T16:26:40,255: [io /Users/chris/dev/personal/test/my-fun-foo-test] PERF: {"ru_nivcsw": 14653, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/personal/test/my-fun-foo-test", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1469478398.6664381, "pid": 2572, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.88504499999999997, "elapsed_time": 1.589172, "ru_idrss": 0, "user_time": 0.485155, "ru_maxrss": 75407360, "ru_inblock": 4640, "ru_minflt": 18408, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 3499}
2016-07-25T16:26:40,255: [io /Users/chris/dev/personal/test/my-fun-foo-test] crawl complete
2016-07-26T17:22:36,949: [io /Users/chris/dev/olo/mobile-web] getattrlist(/Users/chris/dev/olo/mobile-web/.git/MERGE_MSG) failed: No such file or directory
2016-07-29T20:44:26,425: [io /Users/chris/dev/personal/test/my-fun-foo-test] getattrlist(/Users/chris/dev/personal/test/my-fun-foo-test/node_modules/ember-cli/node_modules/broccoli-babel-transpiler/node_modules/babel-core/node_modules/json5/test/parse-cases/numbers) failed: No such file or directory
2016-07-29T20:44:27,892: [io /Users/chris/dev/personal/test/my-fun-foo-test] getattrlist(/Users/chris/dev/personal/test/my-fun-foo-test/node_modules/ember-cli/node_modules/npm/node_modules/node-gyp/node_modules/path-array/node_modules/array-index/node_modules/es6-symbol/node_modules/es5-ext/test/string/#) failed: No such file or directory
2016-07-29T20:44:28,227: [io /Users/chris/dev/personal/test/my-fun-foo-test] getattrlist(/Users/chris/dev/personal/test/my-fun-foo-test/node_modules/ember-cli/node_modules/testem/node_modules/npmlog/node_modules/gauge) failed: No such file or directory
2016-07-29T20:44:30,255: [io /Users/chris/dev/personal/test/my-fun-foo-test] getattrlist(/Users/chris/dev/personal/test/my-fun-foo-test/node_modules/ember-cli-uglify/node_modules/broccoli-uglify-sourcemap/node_modules/lodash/internal) failed: No such file or directory
2016-07-29T20:44:31,278: [notify /Users/chris/dev/personal/test/my-fun-foo-test] kFSEventStreamEventFlagRootChanged /Users/chris/dev/personal/test/my-fun-foo-test, cancel watch
2016-07-30T07:31:26,297: [client=0x7fb3a97908c0:stm=0x7fb3af3bb600] path /Users/chris/dev/olo/mw-upgrade is on filesystem type hfs
2016-07-30T07:31:26,297: [client=0x7fb3a97908c0:stm=0x7fb3af3bb600] root /Users/chris/dev/olo/mw-upgrade using watcher mechanism fsevents (auto was requested)
2016-07-30T07:31:26,991: [io /Users/chris/dev/olo/mw-upgrade] PERF: {"ru_nivcsw": 11869, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mw-upgrade", "recrawl_count": 0, "number": 3, "watcher": "fsevents"}}, "start_time": 1469878286.298274, "pid": 2572, "description": "full-crawl", "ru_msgrcv": 46, "ru_majflt": 0, "ru_msgsnd": 29, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.36436400000000002, "elapsed_time": 0.69308099999999995, "ru_idrss": 0, "user_time": 0.16755400000000001, "ru_maxrss": 0, "ru_inblock": 917, "ru_minflt": 217, "ru_nswap": 0, "ru_oublock": 180, "ru_nsignals": 0, "ru_nvcsw": 926}
2016-07-30T07:31:26,991: [io /Users/chris/dev/olo/mw-upgrade] crawl complete
2016-08-03T07:30:02,454: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-08-03T07:30:02,460: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-08-03T07:30:02,461: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-08-03T07:30:02,461: [listener] path /Users/chris/dev/olo/mw-upgrade is on filesystem type hfs
2016-08-03T07:30:02,462: [listener] root /Users/chris/dev/olo/mw-upgrade using watcher mechanism fsevents (auto was requested)
2016-08-03T07:30:02,462: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-08-03T07:30:02,462: [listener] raised file limit to 50000
2016-08-03T07:30:02,462: [listener] Using socket from launchd as listening socket
2016-08-03T07:30:04,807: [io /Users/chris/dev/olo/mw-upgrade] PERF: {"ru_nivcsw": 16035, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mw-upgrade", "recrawl_count": 0, "number": 2, "watcher": "fsevents"}}, "start_time": 1470223802.4627509, "pid": 441, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 0, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.63779699999999995, "elapsed_time": 2.3451659999999999, "ru_idrss": 0, "user_time": 0.34256300000000001, "ru_maxrss": 53739520, "ru_inblock": 3919, "ru_minflt": 13120, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 3212}
2016-08-03T07:30:04,808: [io /Users/chris/dev/olo/mw-upgrade] crawl complete
2016-08-03T07:30:04,816: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 16098, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1470223802.4618919, "pid": 441, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.64346800000000004, "elapsed_time": 2.3546619999999998, "ru_idrss": 0, "user_time": 0.34801599999999999, "ru_maxrss": 54341632, "ru_inblock": 3927, "ru_minflt": 13265, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 3214}
2016-08-03T07:30:04,816: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-08-03T10:40:37,881: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-08-03T10:40:37,882: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-08-03T10:40:37,882: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-08-03T10:40:37,887: [listener] path /Users/chris/dev/olo/mw-upgrade is on filesystem type hfs
2016-08-03T10:40:37,887: [listener] root /Users/chris/dev/olo/mw-upgrade using watcher mechanism fsevents (auto was requested)
2016-08-03T10:40:37,892: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-08-03T10:40:37,892: [listener] raised file limit to 50000
2016-08-03T10:40:37,893: [listener] Using socket from launchd as listening socket
2016-08-03T10:40:39,050: [io /Users/chris/dev/olo/mw-upgrade] PERF: {"ru_nivcsw": 23998, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mw-upgrade", "recrawl_count": 0, "number": 2, "watcher": "fsevents"}}, "start_time": 1470235237.892242, "pid": 3190, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 0, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.62137299999999995, "elapsed_time": 1.1578489999999999, "ru_idrss": 0, "user_time": 0.34594999999999998, "ru_maxrss": 52125696, "ru_inblock": 3181, "ru_minflt": 12725, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 78}
2016-08-03T10:40:39,050: [io /Users/chris/dev/olo/mw-upgrade] crawl complete
2016-08-03T10:40:39,120: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 24367, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1470235237.8873961, "pid": 3190, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.64732599999999996, "elapsed_time": 1.2330179999999999, "ru_idrss": 0, "user_time": 0.363817, "ru_maxrss": 54079488, "ru_inblock": 3198, "ru_minflt": 13200, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 79}
2016-08-03T10:40:39,120: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-08-04T14:15:46,536: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-08-04T14:15:46,537: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-08-04T14:15:46,537: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-08-04T14:15:46,540: [listener] path /Users/chris/dev/olo/mw-upgrade is on filesystem type hfs
2016-08-04T14:15:46,540: [listener] root /Users/chris/dev/olo/mw-upgrade using watcher mechanism fsevents (auto was requested)
2016-08-04T14:15:46,548: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-08-04T14:15:46,548: [listener] raised file limit to 50000
2016-08-04T14:15:46,549: [listener] Using socket from launchd as listening socket
2016-08-04T14:15:47,429: [io /Users/chris/dev/olo/mw-upgrade] PERF: {"ru_nivcsw": 15592, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mw-upgrade", "recrawl_count": 0, "number": 2, "watcher": "fsevents"}}, "start_time": 1470334546.548919, "pid": 3177, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 0, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.64966299999999999, "elapsed_time": 0.88083199999999995, "ru_idrss": 0, "user_time": 0.33724900000000002, "ru_maxrss": 52068352, "ru_inblock": 3865, "ru_minflt": 12711, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 3219}
2016-08-04T14:15:47,429: [io /Users/chris/dev/olo/mw-upgrade] crawl complete
2016-08-04T14:15:47,456: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 15681, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1470334546.540261, "pid": 3177, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.67042000000000002, "elapsed_time": 0.91666899999999996, "ru_idrss": 0, "user_time": 0.35224100000000003, "ru_maxrss": 54595584, "ru_inblock": 3906, "ru_minflt": 13327, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 3235}
2016-08-04T14:15:47,456: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-08-10T12:51:57,753: [io /Users/chris/dev/olo/mw-upgrade] root /Users/chris/dev/olo/mw-upgrade has had no activity in 432000 seconds and has no triggers or subscriptions, cancelling watch.  Set idle_reap_age_seconds in your .watchmanconfig to control this behavior
2016-08-12T15:12:03,423: [io /Users/chris/dev/olo/mobile-web] root /Users/chris/dev/olo/mobile-web has had no activity in 432000 seconds and has no triggers or subscriptions, cancelling watch.  Set idle_reap_age_seconds in your .watchmanconfig to control this behavior
2016-08-15T11:04:29,914: [client=0x7ff29778f990:stm=0x7ff2977b95f0] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-08-15T11:04:29,914: [client=0x7ff29778f990:stm=0x7ff2977b95f0] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-08-15T11:04:30,612: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 1867, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 3, "watcher": "fsevents"}}, "start_time": 1471273469.9149129, "pid": 3177, "description": "full-crawl", "ru_msgrcv": 55, "ru_majflt": 0, "ru_msgsnd": 38, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.30976999999999999, "elapsed_time": 0.69773700000000005, "ru_idrss": 0, "user_time": 0.134024, "ru_maxrss": 0, "ru_inblock": 1360, "ru_minflt": 593, "ru_nswap": 0, "ru_oublock": 537, "ru_nsignals": 0, "ru_nvcsw": 1366}
2016-08-15T11:04:30,612: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-08-21T07:35:40,149: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-08-21T07:35:40,150: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-08-21T07:35:40,150: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-08-21T07:35:40,151: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-08-21T07:35:40,151: [listener] raised file limit to 50000
2016-08-21T07:35:40,151: [listener] Using socket from launchd as listening socket
2016-08-21T07:35:41,448: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 3038, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1471779340.1515169, "pid": 2970, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.34641499999999997, "elapsed_time": 1.2967580000000001, "ru_idrss": 0, "user_time": 0.18157899999999999, "ru_maxrss": 28807168, "ru_inblock": 2025, "ru_minflt": 7031, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 1927}
2016-08-21T07:35:41,448: [io /Users/chris/dev/olo/mobile-web] crawl complete
2016-08-22T14:17:57,335: [io /Users/chris/dev/olo/mobile-web] getattrlist(/Users/chris/dev/olo/mobile-web/elm-stuff/packages/elm-lang-core-a46ebed/tests/Test/Dict.elm) failed: No such file or directory
2016-08-22T14:53:31,292: [io /Users/chris/dev/olo/mobile-web] getattrlist(/Users/chris/dev/olo/mobile-web/node_modules/.staging/socket.io-727b02b6/package.json.837770351) failed: No such file or directory
2016-09-05T16:22:13,096: [io /Users/chris/dev/olo/mobile-web] root /Users/chris/dev/olo/mobile-web has had no activity in 432000 seconds and has no triggers or subscriptions, cancelling watch.  Set idle_reap_age_seconds in your .watchmanconfig to control this behavior
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x000000010d64ecd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fff97c4a52a _sigtramp + 26
2   ???                                 0x000000000000ffff 0x0 + 65535
3   watchman                            0x000000010d65f46d run_service + 695
4   watchman                            0x000000010d65e8ad main + 401
5   libdyld.dylib                       0x00007fff96aeb5ad start + 1
6   ???                                 0x0000000000000007 0x0 + 7
2016-09-08T19:33:09,565: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-09-08T19:33:09,565: [listener] file limit is 256 kern.maxfilesperproc=50000
2016-09-08T19:33:09,565: [listener] raised file limit to 50000
2016-09-08T19:33:09,566: [listener] Using socket from launchd as listening socket
2016-09-09T13:17:52,377: [client=0x7fd7fc200060:stm=0x7fd7fc200050] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-09-09T13:17:52,377: [client=0x7fd7fc2003c0:stm=0x7fd7fc200040] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-09-09T13:17:52,377: [client=0x7fd7fc200780:stm=0x7fd7fc2006c0] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-09-09T13:17:52,377: [client=0x7fd7fc2003c0:stm=0x7fd7fc200040] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-09-09T13:17:52,377: [client=0x7fd7fc200060:stm=0x7fd7fc200050] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-09-09T13:17:52,377: [client=0x7fd7fc200780:stm=0x7fd7fc2006c0] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-09-09T13:17:52,761: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 718, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1473441472.378268, "pid": 478, "description": "full-crawl", "ru_msgrcv": 15, "ru_majflt": 1, "ru_msgsnd": 10, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.225832, "elapsed_time": 0.38329999999999997, "ru_idrss": 0, "user_time": 0.100212, "ru_maxrss": 28041216, "ru_inblock": 421, "ru_minflt": 6859, "ru_nswap": 0, "ru_oublock": 4, "ru_nsignals": 0, "ru_nvcsw": 422}
2016-09-09T13:17:52,761: [io /Users/chris/dev/olo/mobile-web] crawl complete
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x000000010c16ccd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fff8f38152a _sigtramp + 26
2   ???                                 0x0000000000000000 0x0 + 0
3   watchman                            0x000000010c17d46d run_service + 695
4   watchman                            0x000000010c17c8ad main + 401
5   libdyld.dylib                       0x00007fff97e525ad start + 1
6   ???                                 0x0000000000000007 0x0 + 7
2016-09-09T21:08:14,474: [listener] Watchman 4.6.0 <no build info set> starting up on iMac.local
2016-09-09T21:08:14,477: [listener] path /Users/chris/dev/olo/mobile-web is on filesystem type hfs
2016-09-09T21:08:14,478: [listener] root /Users/chris/dev/olo/mobile-web using watcher mechanism fsevents (auto was requested)
2016-09-09T21:08:14,479: [listener] file limit is 2560 kern.maxfilesperproc=50000
2016-09-09T21:08:14,479: [listener] raised file limit to 50000
2016-09-09T21:08:14,479: [listener] Using socket from launchd as listening socket
2016-09-09T21:08:17,318: [io /Users/chris/dev/olo/mobile-web] PERF: {"ru_nivcsw": 5985, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/chris/dev/olo/mobile-web", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1473469694.479569, "pid": 1005, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 2, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.48527999999999999, "elapsed_time": 2.8385759999999998, "ru_idrss": 0, "user_time": 0.184692, "ru_maxrss": 25538560, "ru_inblock": 2069, "ru_minflt": 6233, "ru_nswap": 0, "ru_oublock": 147, "ru_nsignals": 0, "ru_nvcsw": 2087}
2016-09-09T21:08:17,318: [io /Users/chris/dev/olo/mobile-web] crawl complete
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x000000010e443cd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fffc4aaebba _sigtramp + 26
2   ???                                 0x0000ffff00001fa0 0x0 + 281470681751456
3   watchman                            0x000000010e45446d run_service + 695
4   watchman                            0x000000010e4538ad main + 401
5   libdyld.dylib                       0x00007fffc48a2255 start + 1

@sivakumar-kailasam
Copy link

I ran into this issue as well. Here's some logs I could gather, hope it has some useful info. Had to mask some of the data, but if any of the maintainers need the actual log I can send it over other channels.

2016-09-10T10:33:46,812: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/yuidoc) errno=2 tlen=-1
2016-09-10T10:33:49,231: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] getattrlist(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/ember-cli-release/node_modules/npm/test/tap) failed: No such file or directory
2016-09-10T10:33:50,758: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] getattrlist(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/lodash-node/compat/internal) failed: No such file or directory
2016-09-10T10:41:07,375: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] getattrlist(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.staging/are-we-there-yet-8e476ec1/package.json.1689863940) failed: No such file or directory
2016-09-12T10:36:10,472: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/strip-json-comments) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/tap-parser) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/testem) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/uglifyjs) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/user-home) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/uuid) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/which) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/window-size) errno=2 tlen=-1
2016-09-12T10:36:10,473: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] readlink(/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app/node_modules/.bin/yuidoc) errno=2 tlen=-1
2016-09-12T10:36:48,181: [notify /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app: kFSEventStreamEventFlagUserDropped: scheduling a tree recrawl
2016-09-12T10:36:48,383: [notify /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] root /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app using watcher mechanism fsevents (auto was requested)
2016-09-12T10:36:48,485: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] PERF: {"ru_nivcsw": 220, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app", "recrawl_count": 1, "number": 3, "watcher": "fsevents"}}, "start_time": 1473656808.3859079, "pid": 953, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 0, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 0.068027000000000004, "elapsed_time": 0.099881999999999999, "ru_idrss": 0, "user_time": 0.028583999999999998, "ru_maxrss": 0, "ru_inblock": 0, "ru_minflt": 536, "ru_nswap": 0, "ru_oublock": 0, "ru_nsignals": 0, "ru_nvcsw": 5}
2016-09-12T10:36:48,485: [io /Users/skailasam/Documents/x180/frontend-apps/a-really-swag-app] recrawl complete
Terminating due to signal 15 Terminated generated by pid=1 uid=0.  (0x0)
0   watchman                            0x000000010b2becd9 crash_handler + 345
1   libsystem_platform.dylib            0x00007fff98f4a52a _sigtramp + 26
2   watchman                            0x000000010b2e7485 w_client_lock + 1861
3   watchman                            0x000000010b2cf46d run_service + 695
4   watchman                            0x000000010b2ce8ad main + 401
5   libdyld.dylib                       0x00007fff9138f5ad start + 1
6   ???                                 0x0000000000000007 0x0 + 7

@chriskrycho
Copy link

Follow-up after looking at that log: it hasn't stored any data there since I upgraded watchman; did you folks move where it logs to? Or is it just not logging anything on this?

@wez
Copy link
Contributor

wez commented Sep 14, 2016

Maybe the problem is that launchd just isn't even starting the 4.7 binary?
If you run console.app and filter by watchman, is launchd reporting anything interesting?

What are the contents of your ~/Library/LaunchAgents/com.github.facebook.watchman.plist ?

@chriskrycho
Copy link

Here's that plist content:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "https://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>Label</key>
    <string>com.github.facebook.watchman</string>
    <key>Disabled</key>
    <false/>
    <key>ProgramArguments</key>
    <array>
        <string>/usr/local/Cellar/watchman/4.7.0/libexec/bin/watchman</string>
        <string>--foreground</string>
        <string>--logfile=/usr/local/var/run/watchman/chris-state/log</string>
        <string>--log-level=1</string>
        <string>--sockname=/usr/local/var/run/watchman/chris-state/sock</string>
        <string>--statefile=/usr/local/var/run/watchman/chris-state/state</string>
        <string>--pidfile=/usr/local/var/run/watchman/chris-state/pid</string>
    </array>
    <key>Sockets</key>
    <dict>
        <key>sock</key>
        <dict>
            <key>SockPathName</key>
            <string>/usr/local/var/run/watchman/chris-state/sock</string>
            <key>SockPathMode</key>
            <integer>384</integer>
        </dict>
    </dict>
    <key>KeepAlive</key>
    <dict>
        <key>Crashed</key>
        <true/>
    </dict>
    <key>RunAtLoad</key>
    <true/>
    <key>EnvironmentVariables</key>
    <dict>
        <key>PATH</key>
        <string><![CDATA[/Users/chris/.nodenv/versions/5.9.0/bin:/usr/local/Cellar/nodenv/1.0.0/libexec:/Users/chris/.rbenv/shims:/Users/chris/.nodenv/shims:/Users/chris/.pyenv/shims:/Users/chris/bin:/Users/chris/.cargo/bin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/Library/TeX/texbin]]></string>
    </dict>
    <key>ProcessType</key>
    <string>Interactive</string>
    <key>Nice</key>
    <integer>-5</integer>
</dict>
</plist>

And I found the relevant console logs in the system.log entry—things moved around a little in 10.12:

Sep 14 09:57:06 iMac com.apple.xpc.launchd[1] (com.github.facebook.watchman[60232]): Could not find and/or execute program specified by service: 2: No such file or directory: /usr/local/Cellar/watchman/4.6.0/libexec/bin/watchman
Sep 14 09:57:06 iMac com.apple.xpc.launchd[1] (com.github.facebook.watchman[60232]): Service setup event to handle failure and will not launch until it fires.
Sep 14 10:04:59 iMac com.apple.xpc.launchd[1] (com.github.facebook.watchman[61709]): Could not find and/or execute program specified by service: 2: No such file or directory: /usr/local/Cellar/watchman/4.6.0/libexec/bin/watchman
Sep 14 10:04:59 iMac com.apple.xpc.launchd[1] (com.github.facebook.watchman[61709]): Service setup event to handle failure and will not launch until it fires.

Looks like launchd is trying to hit the old one. Nothing stands out as to why in the launchd plist, though. Could it be an issue with the socket?

Aside: I haven't rebooted in that interval.

@wez
Copy link
Contributor

wez commented Sep 14, 2016

ok, please try:

launchctl unload ~/Library/LaunchAgents/com.github.facebook.watchman.plist
watchman version

@chriskrycho
Copy link

/Users/chris/Library/LaunchAgents/com.github.facebook.watchman.plist: Could not find specified service
{
    "version": "4.7.0"
}

@wez
Copy link
Contributor

wez commented Sep 14, 2016

I think you're now all set. I think we need to more aggressively unload and reinstate the service when we try to launch it via launchd.

@wez wez changed the title Watchman stuck when sending commands Force launchd plist file to be reloaded when launching watchman Sep 14, 2016
@wez wez reopened this Sep 14, 2016
@wez
Copy link
Contributor

wez commented Sep 14, 2016

@chriskrycho thanks for working through this with me!

@chriskrycho
Copy link

No problem! Happy to be able to help!

@wez
Copy link
Contributor

wez commented Sep 14, 2016

@chriskrycho I'm trying to figure out how you ended up in that broken state. The spawning logic in watchman is to launchctl unload, generate a correct plist and then ask launchd to start it up. I'd expect to see the 4.6 brew path in a situation that manifests this way, so it's puzzling to me that we have the 4.7 path in there. :-/

Does the last timestamp in your 4.6 log (2016-09-09T21:08:17) correspond to roughly when you upgraded watchman?

Do you happen to recall running any specific watchman or ember commands around the time that things stopped working?

@chriskrycho
Copy link

  1. That does correspond to when I upgraded.
  2. What's particularly weird, though, is that I was running tests just fine yesterday, and then it stopped working fine today—made no changes to either in the interval. I did have a couple Skype-induced immediate sign-outs happen this morning, which force-killed my iTerm processes.

No idea whether relevant: the pid file had a PID in it which from my ps searching didn't exist anywhere on the system when I pulled it back up.

wez added a commit to wez/watchman that referenced this issue Sep 14, 2016
Summary: in facebook#358 we ended up
in a state where the contents of the plist were correct but launchd
still thought that it should be monitoring the older 4.6 binary.

I don't know how we ended up in such a state, as we unload before we
write out the new plist.

My working theory is that the unload failed for some unknown reason but
we carried on anyway.

Also, this nugget from the man page:

> NOTE: Due to bugs in the previous implementation and long-standing
> client expectations around those bugs, the load and unload subcommands
> will only return a non-zero exit code due to improper usage.
> Otherwise, zero is always returned.

This is a speculative diff to add the `-F` force flag in.  I have no way
to prove whether this will solve this, only that it doesn't break
spawning watchman for me today.

Test Plan: with watchman not running and my plist referencing the
internal FB build of watchman, build and run watchman from the checkout
on my mac as `./watchman version`.  Inspect the plist and observe that
the executable path has changed from the installed location of the
binary to the path to my checkout and that we got a valid watchman
version response.
@wez
Copy link
Contributor

wez commented Sep 15, 2016

Over in #361 @onpaws asked a couple of questions that I think are worth answering, but over here so that we keep a single thread going. I'm paraphrasing the questions to make them easier to answer :-)

I'm also going to ask and answer a couple of other questions that give some more context.

Why doesn't brew uninstall remove the launchd and other state?

Watchman has a slightly unusual model in that it runs a separate server process for each user. This is important because it allows multiple users to be isolated from each other both from a resource usage and also a security perspective. Launchd registration happens for you on-demand and is out of the sight of what homebrew can see today, so uninstallation just doesn't know about them.

In addition, the state dir is intended to survive across upgrades: it holds persistent information such as the set of watches that you had before the upgrade so that those can be re-started and recrawled for you when you next start it, and also when you first log in so that those are ready to be queried.

Why not keep the state in /tmp?

This is a security risk; the state files can record triggers and a malicious user with access to your stuff in /tmp can then cause some other program to run as you. We avoid this by installing to a directory that has appropriate permissions configured, and watchman will refuse to start if those permissions are too broad.

Why did removing the state dir fix the launchd issue?

The state dir holds a unix domain socket. The launchd configuration is set up so that connecting to that unix domain socket causes launchd to spawn the watchman server process. While launchd had cached the invalid configuration it would try to spawn the old homebrew path and then fail, leaving the CLI watchman process in a hung state.

Removing the socket file broke this connection and caused watchman to re-register the launchd configuration.

Ah, so the state directory is secondary to the real problem?

Yep, the real problem is that the initial attempt to unload the launchd configuration seemingly failed silently, which is what prompted the code change in #360.

Is there anything else we can do to make this more resilient?

If there's a way to have brew some code on uninstall, it would be great to unload the launchd.plist and/or speculatively kill any lingering watchman processes. I can't find such a hook though. An alternative would be to do this at install time, however, in theory, brew can allow multiple versions of watchman to be installed on the system at the same time, so this kind of behavior is a bit off.

ghost pushed a commit that referenced this issue Sep 16, 2016
Summary:
in #358 we ended up
in a state where the contents of the plist were correct but launchd
still thought that it should be monitoring the older 4.6 binary.

I don't know how we ended up in such a state, as we unload before we
write out the new plist.

My working theory is that the unload failed for some unknown reason but
we carried on anyway.

Also, this nugget from the man page:

> NOTE: Due to bugs in the previous implementation and long-standing
> client expectations around those bugs, the load and unload subcommands
> will only return a non-zero exit code due to improper usage.
> Otherwise, zero is always returned.

This is a speculative diff to add the `-F` force flag in.  I have no way
to prove whether this will solve this, only that it doesn't break
spawning watchman for me today.
Closes #360

Reviewed By: sid0

Differential Revision: D3874674

Pulled By: wez

fbshipit-source-id: daa7c1581940d286d601546d1ab892c2f1dbddcc
@clundie
Copy link

clundie commented Sep 26, 2016

Thank you for the insights. This was causing my Atom Helper process to crash on exit (even with plugins disabled including Nuclide), and also to have high CPU usage when idle.

@benhughes
Copy link

I see the issue is still open, I experienced this and launchctl unload ~/Library/LaunchAgents/com.github.facebook.watchman.plist seemed to fix it. While I was debugging I thought it might be a permission issue as I could get it to not hang if I called watchman with sudo. Not sure if that helps at all but thought I'd leave it here.

@p1xelHer0
Copy link

Just wanted to chime in and say that launchctl unload ~/Library/LaunchAgents/com.github.facebook.watchman.plist solved my issue: I was trying to start my react-native app using node node_modules/react-native/local-cli/cli.js start and it would just hang on the watchman process. After running the the launchctl unload above it started again with no problems whatsoever.

Thanks!

@amurchick
Copy link

Anybody have idea how to fix watchman hangs?
launchctl unload ~/Library/LaunchAgents/com.github.facebook.watchman.plist does not helps for me.
watchman

Details in #371

@irishgordo
Copy link

@amurchick - Yeah, I'm having the same issue

Darwin Dev-iMac-4.local 16.1.0 Darwin Kernel Version 16.1.0: Thu Oct 13 21:26:57 PDT 2016; root:xnu-3789.21.3~60/RELEASE_X86_64 x86_64

@wez
Copy link
Contributor

wez commented Nov 1, 2016

I've been a bit quiet on this issue. The game plan is to remove socket activation from the launchd registration in the next release to homebrew. We're not quite in a position to do that right now (in the middle of a big refactor), so if you happen to hit this, the recommendation is to run the launchctl unload command to resolve it:

launchctl unload -F ~/Library/LaunchAgents/com.github.facebook.watchman.plist
watchman version

@dijonkitchen
Copy link

dijonkitchen commented Jan 11, 2017

Note that the -F flag above forces the loading of the plist, ignoring the disable key.

I ran the command without -F and it worked fine, just like it did for others. Opinions on what's better?

Ref:
https://developer.apple.com/legacy/library/documentation/Darwin/Reference/ManPages/man1/launchctl.1.html

facebook-github-bot pushed a commit that referenced this issue Jan 23, 2017
Summary:
This will help prevent a situation like
#358 from having a similar impact in
the future.

Launchd will still launch watchman at startup and keep it running if it falls
over, but should get out of the way when we upgrade in the future.

I'll look at adding some explicit unloading of the plist at installation time
in the homebrew recipe.

Reviewed By: sid0

Differential Revision: D4417672

fbshipit-source-id: b4d4597107f26f2e4e51ecd540dfb36586cfa44c
wez added a commit to wez/homebrew-core that referenced this issue Jan 30, 2017
This is taking a run at: facebook/watchman#358

Watchman installs and updates its own launchd.plist file on behalf of the user; it is not integrated with `brew services`.
In the linked issue, watchman would stop working for some homebrew users.  The problem was that the launchd.plist used socket activation to set up the service, and because launchd is maintaining the socket, and the socket connection attempt just hangs, watchman never had a chance to fix up the plist and things stayed broken.

To help solve this, we're forcing an unload in the post-install portion of the recipe.
MikeMcQuaid pushed a commit to Homebrew/homebrew-core that referenced this issue Feb 10, 2017
This is taking a run at: facebook/watchman#358

Watchman installs and updates its own launchd.plist file on behalf of the user; it is not integrated with `brew services`.
In the linked issue, watchman would stop working for some homebrew users.  The problem was that the launchd.plist used socket activation to set up the service, and because launchd is maintaining the socket, and the socket connection attempt just hangs, watchman never had a chance to fix up the plist and things stayed broken.

To help solve this, we're forcing an unload in the post-install portion of the recipe.
@wez wez closed this as completed Mar 21, 2017
@simplenotezy
Copy link

I still have this issue - no solution so far.

@bloempot71
Copy link

This issue seems to be present when you have your home folder on a different (external?) drive from your system. At least with me macOS High Sierra selected "Ignore ownership on this volume" for the external drive. By disabling this odd feature the "Caller specified a plist with bad ownership/permissions" issue was solved.

Links
OpenEmu/OpenEmu#2384
https://support.apple.com/kb/PH25288?locale=en_US

@shafqatbari
Copy link

I am facing the same issue with latest build I have this Version
C:\Users\Shafqat>watchman -v
20201213.172817.0

And Facing This Issue

2020-12-16T12:11:33,518: [cli] Failed to spawn watchman server; it exited with code 3.
Check the log file at C:/Users/Shafqat/AppData/Local/watchman/log for more information

Watchman: watchman --no-pretty get-sockname returned with exit code=1, signal=null, stderr= 2020-12-16T12:11:33,518: [cli] Failed to spawn watchman server; it exited with code 3.
Check the log file at C:/Users/Shafqat/AppData/Local/watchman/log for more information

@CWSites
Copy link

CWSites commented Feb 8, 2021

I'm also running into this problem. I'm on watchman version 4.9.0 I've tried everything I can find, updated brew, reinstalled watchman, wiped node_modules and ran yarn again.

I'm using the latest create-react-app with react-scripts version 4.0.2

Followed all steps shown here: https://create-react-app.dev/docs/troubleshooting none of them resolve my problem.

@chr4ss12
Copy link

Had the same problem with watchman hanging, I noticed that it started happening randomly and my react-native project stopped building, it was frozen, it took me forever to figure out that watchman was the culprit, even though I've reinstalled watchman multiple times.

Version: 2021.06.07.00

I am lucky it only took 4 hours to find the problem & solution, the fix was to delete the state folder: /usr/local/var/run/watchman/chris-state/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests