Watchman: Watchman shutdown issue

[cpojer]

See https://github.com/facebook/jest/issues/1618#issuecomment-245043672

[wez]

Please run this in one window:

watchman shutdown-server
watchman --foreground --logfile=/dev/stdout

then in another, try running jest.

Please share the output from the foreground watchman command.

[inyono]

Okay, interesting: watchman shutdown-server didn't do anything (infinite loop). I stopped the process and ran the second command instead. Jest worked then and I got logs:

2016-09-06T21:36:20,598: [listener] Watchman 4.6.0 <no build info set> starting up on Jonass-MacBook-Pro.local
2016-09-06T21:36:20,600: [listener] file limit is 4864 kern.maxfilesperproc=10240
2016-09-06T21:36:20,600: [listener] raised file limit to 10240
2016-09-06T21:36:20,600: [listener] launchd checkin failed: No such process
2016-09-06T21:36:30,693: [client=0x7fefa34093a0:stm=0x7fefa34092c0] path /Users/inyono/Projects/jest is on filesystem type hfs
2016-09-06T21:36:30,694: [client=0x7fefa34093a0:stm=0x7fefa34092c0] root /Users/inyono/Projects/jest using watcher mechanism fsevents (auto was requested)
2016-09-06T21:36:33,124: [io /Users/inyono/Projects/jest] PERF: {"ru_nivcsw": 2087, "meta": {"root": {"case_sensitive": false, "ticks": 2, "path": "/Users/inyono/Projects/jest", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}}, "start_time": 1473190590.6959829, "pid": 96734, "description": "full-crawl", "ru_msgrcv": 0, "ru_majflt": 1, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 1.140212, "elapsed_time": 2.4288889999999999, "ru_idrss": 0, "user_time": 0.34578500000000001, "ru_maxrss": 44830720, "ru_inblock": 3874, "ru_minflt": 10944, "ru_nswap": 0, "ru_oublock": 1, "ru_nsignals": 0, "ru_nvcsw": 3875}
2016-09-06T21:36:33,125: [io /Users/inyono/Projects/jest] crawl complete
2016-09-06T21:36:33,130: [client=0x7fefa34093a0:stm=0x7fefa34092c0] PERF: {"ru_nivcsw": 2115, "meta": {"root": {"case_sensitive": false, "ticks": 3, "path": "/Users/inyono/Projects/jest", "recrawl_count": 0, "number": 1, "watcher": "fsevents"}, "args": ["watch-project", "/Users/inyono/Projects/jest"]}, "start_time": 1473190590.693465, "pid": 96734, "description": "dispatch_command:watch-project", "ru_msgrcv": 0, "ru_majflt": 5, "ru_msgsnd": 0, "ru_ixrss": 0, "version": "4.6.0", "system_time": 1.141705, "elapsed_time": 2.4368660000000002, "ru_idrss": 0, "user_time": 0.35175200000000001, "ru_maxrss": 45477888, "ru_inblock": 3874, "ru_minflt": 11101, "ru_nswap": 0, "ru_oublock": 3, "ru_nsignals": 0, "ru_nvcsw": 3875}

After stopping this process, watchman works again just fine... Maybe watchman was in some invalid state somehow?

[wez]

Based on your 4.5 logs from earlier, my gut feeling is that you hit one of the weird unterminated loop on shutdown conditions that we fixed in 4.6 while upgrading. https://github.com/facebook/watchman/commit/5e7d4a0bdead2c98fd9f117229c5a3d0e3ba0cce is one that I can find reasonably easily, but there were a couple of related fixes

[inyono]

Okay. Thanks for your help! :)

[wez]

Thanks for reporting and working on getting more info! I'll close this out and relabel it so that it doesn't give the wrong impression to future searches

[mCzolko]

Hi, I'm having same issue and when I run watchman --foreground --logfile=/dev/stdout
I'm getting:

2016-11-08T00:58:25,816: [notify 0x7fdc29e07318 /Users/michael/workspace/native-app/MyApplication] kFSEventStreamEventFlagRootChanged /Users/ejay/workspace/native-app/MyApplication, cancel watch
2016-11-08T00:58:54,494: [client=0x7fdc29fdc148:stm=0x7fdc30ba67d0] Unilateral payload for sub sane-sub {"settled": true}
2016-11-08T00:58:54,533: [client=0x7fdc2c003a08:stm=0x7fdc2c000600] Unilateral payload for sub sane-sub {"settled": true}
2016-11-08T00:58:54,536: [client=0x7fdc29fdc148:stm=0x7fdc30ba67d0] Unilateral payload for sub sane-sub {"settled": true}
Terminating due to signal 11 Segmentation fault generated by pid=0 uid=0. address not mapped to object (0x0)
0   watchman                            0x0000000100325759 _ZL13crash_handleriP9__siginfoPv + 347
1   libsystem_platform.dylib            0x00007fff8c8c9bba _sigtramp + 26
2   watchman                            0x000000010035f2de _ZN8json_refaSEOS_ + 20
3   watchman                            0x00000001003219b2 _ZN6detail22estimateSpaceToReserveIPKcJA3_cA28_c8w_stringA2_cPcS6_EEEmmRKT_DpRKT0_ + 109
4   watchman                            0x0000000100321815 _ZN8w_string5buildIJPcRA4_KcPS2_RA3_S2_RA28_S2_RS_RA2_S2_RS1_SC_EEES_DpOT_ + 121
5   watchman                            0x000000010034d4cb _ZN8watchman3Log3logIJRA28_KcR8w_stringRA2_S2_RPcS8_EEEvNS_8LogLevelEDpOT_ + 183
6   watchman                            0x000000010034c6e0 _ZNSt3__114__thread_proxyINS_5tupleIJZL15make_new_clientP15watchman_streamE3$_0EEEEEPvS6_ + 952
7   libsystem_pthread.dylib             0x00007fff8c8d3aab _pthread_body + 180
8   libsystem_pthread.dylib             0x00007fff8c8d39f7 _pthread_body + 0
9   libsystem_pthread.dylib             0x00007fff8c8d3221 thread_start + 13
Abort trap: 6

[wez]

@mCzolko you are running HEAD when you should be running the 4.7 release branch. Please reinstall watchman according to https://facebook.github.io/watchman/docs/install.html#build-install