Can you file a bug on this and upload the full spindump there? I opened one last week. Case-ID: 18860388 ...this is almost CERTAINLY caused by your ES client. Yes. The question here isn't what revisiond is doing, it's who revisiond is waiting on. Some other thread locked that lock and is now stuck, which is the real issue you need to sort out. It definitely revisiond (well, APFS), that's holding the lock. There are dozens of threads where the shared lock points at revisiond [426] thread 0xc0616d), both for reading and writing. *940 apfs_vnop_getattr + 312 (apfs + 604336) [0xfffffe000beacff0] *940 IORWLockRead + 144 (kernel.release.t6000 + 496568) [0xfffffe00088e53b8] *940 ??? (kernel.release.t6000 + 497548) [0xfffffe00088e578c] *940 ??? (kernel.release.t6000 + 619452) [0xfffffe00089033bc] *940 ??? (kernel.release.t6000 + 624472) [0xfffffe0008904758] (suspended, blocked by krwlock for reading owned by revisiond [426] thread 0xc0616d) *940 apfs_vnop_read + 708 (apfs + 555972) [0xfffffe000bea1304] *940 IORWLockWrite + 184 (kernel.release.t6000 + 496184) [0xfffffe00088e5238] *940 ??? (kernel.release.t6000 + 494304) [0xfffffe00088e4ae0] *940 ??? (kernel.release.t6000 + 619452) [0xfffffe00089033bc] *940 ??? (kernel.release.t6000 + 624472) [0xfffffe0008904758] (blocked by krwlock for writing owned by revisiond [426] thread 0xc0616d) *940 icp_lock_inode + 72 (apfs + 757908) [0xfffffe000bed27d4] *940 IORWLockWrite + 184 (kernel.release.t6000 + 496184) [0xfffffe00088e5238] *940 ??? (kernel.release.t6000 + 494304) [0xfffffe00088e4ae0] *940 ??? (kernel.release.t6000 + 619452) [0xfffffe00089033bc] *940 ??? (kernel.release.t6000 + 624472) [0xfffffe0008904758] (blocked by krwlock for writing owned by revisiond [426] thread 0xc0616d) Only that revisiond thread that doesn't blame another thread / lock.

I don't think that’s a valid bug number. Sorry, it was a TSI, not a bug report. I replied to the DTS email yesterday with the full spin dump. Let me know if you still want a bug report as well. Again, you can see that second lock here if you're curious. There are only 2 other threads in the logs that appear relevant, both from our helper process and both down in APFS. One of them is also stuck inside decmpfs_read_compressed: Thread 0xc06805 DispatchQueue "com.apple.root.default-qos"(13) 940 samples (1-940) priority 46 (base 31) last ran 241692.753s ago 940 start_wqthread + 8 (libsystem_pthread.dylib + 7068) [0x189d0ab9c] 940 _pthread_wqthread + 232 (libsystem_pthread.dylib + 11792) [0x189d0be10] 940 _dispatch_worker_thread2 + 180 (libdispatch.dylib + 83844) [0x189b65784] 940 _dispatch_root_queue_drain + 736 (libdispatch.dylib + 82236) [0x189b6513c] 940 <deduplicated_symbol> + 32 (libdispatch.dylib + 231900) [0x189b899dc] 940 _dispatch_client_callout + 16 (libdispatch.dylib + 113364) [0x189b6cad4] 940 _dispatch_call_block_and_release + 32 (libdispatch.dylib + 7004) [0x189b52b5c] 940 __34-[MyConcurrentQueue performBlock:]_block_invoke (in MyFramework) (MyConcurrentQueue.m:228) + 355392 [0x102a42c40] 940 __66-[MyPathHelper fetchFileTypeForFileAtPath:statData:queue:handler:]_block_invoke.125 (in MyFramework) (MyPathHelper.m:1056) + 43416 [0x1029f6998] 940 pread + 8 (libsystem_kernel.dylib + 9788) [0x189cce63c] *940 ??? (kernel.release.t6000 + 15240) [0xfffffe000886fb88] *940 ??? (kernel.release.t6000 + 1886348) [0xfffffe0008a3888c] *940 ??? (kernel.release.t6000 + 7730436) [0xfffffe0008fcb504] *940 ??? (kernel.release.t6000 + 6448868) [0xfffffe0008e926e4] *940 ??? (kernel.release.t6000 + 6447764) [0xfffffe0008e92294] *940 ??? (kernel.release.t6000 + 2790292) [0xfffffe0008b15394] *940 ??? (kernel.release.t6000 + 2791252) [0xfffffe0008b15754] *940 apfs_vnop_read + 508 (apfs + 555772) [0xfffffe000bea123c] *940 decmpfs_read_compressed + 300 (kernel.release.t6000 + 2955192) [0xfffffe0008b3d7b8] *940 ??? (kernel.release.t6000 + 2946852) [0xfffffe0008b3b724] *940 ??? (kernel.release.t6000 + 2800480) [0xfffffe0008b17b60] *940 apfs_inode_getxattr + 716 (apfs + 1541792) [0xfffffe000bf91de0] *940 IORWLockRead + 144 (kernel.release.t6000 + 496568) [0xfffffe00088e53b8] *940 ??? (kernel.release.t6000 + 497548) [0xfffffe00088e578c] *940 ??? (kernel.release.t6000 + 619452) [0xfffffe00089033bc] *940 ??? (kernel.release.t6000 + 624472) [0xfffffe0008904758] (blocked by krwlock for reading owned by revisiond [426] thread 0xc0616d) Thread 0xc06362 940 samples (1-940) priority 46 (base 31) last ran 241692.753s ago 940 start_wqthread + 8 (libsystem_pthread.dylib + 7068) [0x189d0ab9c] 940 _pthread_wqthread + 232 (libsystem_pthread.dylib + 11792) [0x189d0be10] 940 _dispatch_worker_thread2 + 180 (libdispatch.dylib + 83844) [0x189b65784] 940 _dispatch_root_queue_drain + 736 (libdispatch.dylib + 82236) [0x189b6513c] 940 <deduplicated_symbol> + 32 (libdispatch.dylib + 231900) [0x189b899dc] 940 _dispatch_client_callout + 16 (libdispatch.dylib + 113364) [0x189b6cad4] 940 _dispatch_call_block_and_release + 32 (libdispatch.dylib + 7004) [0x189b52b5c] 940 __34-[MyConcurrentQueue performBlock:]_block_invoke (in MyFramework) (MyConcurrentQueue.m:228) + 355392 [0x102a42c40] 940 __66-[MyPathHelper fetchFileTypeForFileAtPath:statData:queue:handler:]_block_invoke.125 (in MyFramework) (MyPathHelper.m:1056) + 43416 [0x1029f6998] 940 <patched truncated backtrace> 940 pread + 8 (libsystem_kernel.dylib + 9788) [0x189cce63c] *940 ??? (kernel.release.t6000 + 15240) [0xfffffe000886fb88] *940 ??? (kernel.release.t6000 + 1886348) [0xfffffe0008a3888c] *940 ??? (kernel.release.t6000 + 7730436) [0xfffffe0008fcb504] *940 ??? (kernel.release.t6000 + 6448868) [0xfffffe0008e926e4] *940 ??? (kernel.release.t6000 + 6447764) [0xfffffe0008e92294] *940 ??? (kernel.release.t6000 + 2790292) [0xfffffe0008b15394] *940 ??? (kernel.release.t6000 + 2791252) [0xfffffe0008b15754] *940 apfs_vnop_read + 708 (apfs + 555972) [0xfffffe000bea1304] *940 IORWLockWrite + 184 (kernel.release.t6000 + 496184) [0xfffffe00088e5238] *940 ??? (kernel.release.t6000 + 494304) [0xfffffe00088e4ae0] *940 ??? (kernel.release.t6000 + 619452) [0xfffffe00089033bc] *940 ??? (kernel.release.t6000 + 624472) [0xfffffe0008904758] (blocked by krwlock for writing owned by revisiond [426] thread 0xc0616d) I will review these calls and locks some more, but have limited insight into the APFS implementation here. ...which means I suspect you meant "hang", meaning that the problem eventually cleared itself. If the problem clears on its own, that meant someone had to release revisiond to make forward progress. No, it was 3 days later and the problem hadn't resolved. At that time, we tried killing revisiond but it was left a zombie (due to the held lock?). A reboot was required to resolve the problem.

What you'll find is that there are two clients— yours and a (presumably unrelated) 3rd party client. The other ES client is basically a 3rd party logger that's not active. Ours does some auth work, but we're fairly certain in this case it's just monitoring to do reporting and follow-up scans. Do you know exactly what "kicked off" your helper process? Both in terms of the triggering event and the target file? No. At the time, the system had been idle for 2 hours. In this case, we do observe a system update being staged in the background, but not in all other instances. I suspect it was a FILE_NOTIFY_CLOSE. It would be insightful to know if APFS triggers that or related ES events when decompressing a file. A big part of the problem here is that the data we're looking at is being collected LONG (2+ days) after the problem itself actually occurred, which means we don't REALLY know EXACTLY what happened. I will submit unified logs that cover the period in question, but your point remains. That ES check can now act as a sort of "starting gun", since you're now able to generate work targeting the relevant file within a FAR narrower time window than would otherwise occur. Indeed, when I said there were 2 threads involved, I was wrong. That's the conclusion we've been circling too. Not that our ES hooks are directly causing the deadlock, but that by hooking certain OS events and quickly acting on them, we're exercising the file system code in a way that may cause problems. My best explanation for that is that you basically "raced" both threads into the kernel with JUST the right/wrong timing that you triggered this deadlock. The problem is that it doesn't affect many machines, is slow to reproduce, and is not deterministic. That said, we have a tester that tries to simulate the problem with APFS transparent compression, concurrent threads, etc. Will advise if we find something. It's very likely that there is an APFS bug here, so if you haven't already, please file a bug on this and post the bug number back here. FB22345232 It's ALSO very likely that your ES client (possibly both ES clients) are required to actually experience this bug, and you should address it as well. We do whitelist several Apple housekeeping processes and daemons, but not revisiond yet. Are there any other tools directly involved with APFS compression that we should consider?

I mistakenly created that FB ticket on the wrong account. Here is the correct ID: FB22345323

Are you sure it isn't an auth event? Without going into too much detail, it's possible, but unlikely given the methods in the stack that led to the deadlock. Auth events are primarily for security and integrity protection. What are you actually "doing" to the files? I suspect you're copying them, but wouldn't mind confirming that. The method on the stack is -[MyPathHelper fetchFileTypeForFileAtPath:], which is mostly used for scanning and reporting. Having said that, my suggestion to whitelist RevisionD is really about what it "does", not how it's doing it. I was mostly thinking of its interaction with extended attributes, as we see the target threads touching those as well. I will post more detail in the FB ticket, and we can dive deeper there.

Yeah, the resource fork is just another named fork. For APFS compression, my understanding is that it's using a com.apple.decmpfs named fork, and we see those methods from the APFS kext in the stack. Disassembling revisiond and checking the stack crawl, it appears to be working with com.apple.genstore.* xattrs. We are still trying to identify which file(s) are involved, but so far, any logging messes with the timing to hide the problem and lsof just hangs due to the rwlock, but perhaps it's down in .DocumentRevisions-V100. The underlying xattr access is an implementation detail, though it probably is visible to the ES client. I will check to see if calls to extended attributes and named forks (directly or indirectly) are reported that way to the ES hooks. clone the file yourself and then operate on the clone. That's an interesting thought, especially for the copy-on-write features. I will take it back to the team to consider.

A quick test shows it uses the xattr-specific ES events. Not definitive, and may differ on some systems, but this was one of the affected devices. ES_EVENT_TYPE_NOTIFY_DELETEEXTATTR: process=/System/Applications/TextEdit.app/Contents/MacOS/TextEdit path=/Users/matt.slot/Library/Containers/com.apple.TextEdit/Data/tmp/TemporaryItems/NSIRD_TextEdit_ihoZLx/21B97262-CCCD-4DE3-929D-DC322367AC80.rtf xattr=com.apple.genstore.origdisplayname ES_EVENT_TYPE_NOTIFY_DELETEEXTATTR: process=/System/Applications/TextEdit.app/Contents/MacOS/TextEdit path=/Users/matt.slot/Library/Containers/com.apple.TextEdit/Data/tmp/TemporaryItems/NSIRD_TextEdit_ihoZLx/21B97262-CCCD-4DE3-929D-DC322367AC80.rtf xattr=com.apple.genstore.info ES_EVENT_TYPE_NOTIFY_DELETEEXTATTR: process=/System/Applications/TextEdit.app/Contents/MacOS/TextEdit path=/Users/matt.slot/Library/Containers/com.apple.TextEdit/Data/tmp/TemporaryItems/NSIRD_TextEdit_ihoZLx/21B97262-CCCD-4DE3-929D-DC322367AC80.rtf xattr=com.apple.genstore.gen_options ES_EVENT_TYPE_NOTIFY_DELETEEXTATTR: process=/System/Applications/TextEdit.app/Contents/MacOS/TextEdit path=/Users/matt.slot/Library/Containers/com.apple.TextEdit/Data/tmp/TemporaryItems/NSIRD_TextEdit_ihoZLx/21B97262-CCCD-4DE3-929D-DC322367AC80.rtf xattr=com.apple.genstore.orig_perms_v1