search

objective-see / FileMonitor

File Monitor Library (based on Apple's new Endpoint Security Framework)
GNU General Public License v3.0
327 stars 47 forks source link

Are ES_EVENT_TYPE_NOTIFY_WRITE events triggered by iCloud (bird etc) or any better way to log them? #7

Open luckman212 opened 3 years ago

luckman212 commented 3 years ago

I've been trying to use FileMonitor to track down a really annoying and elusive bug with 0-byte files (files getting spuriously emptied and losing their data). I'm trying to trigger this bug while FileMonitor is running, and I'm seeing some weird behavior where it seems as if iCloud's daemons (bird and whatever other daemons run in the background and handle iCloud file sync) are able to modify the filesystem right under the nose of tools like FileMonitor.

Here's a POC script for testing - requires jq (brew install jq)

poor-mans-fsusage.sh

#!/usr/bin/env bash

logfile="$HOME/Desktop/FileMonitor.log"
re="^$HOME/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt"
e_types='[
"ES_EVENT_TYPE_NOTIFY_CLONE",
"ES_EVENT_TYPE_NOTIFY_CREATE",
"ES_EVENT_TYPE_NOTIFY_FCNTL",
"ES_EVENT_TYPE_NOTIFY_RENAME",
"ES_EVENT_TYPE_NOTIFY_SETACL",
"ES_EVENT_TYPE_NOTIFY_SETATTRLIST",
"ES_EVENT_TYPE_NOTIFY_SETEXTATTR",
"ES_EVENT_TYPE_NOTIFY_SETFLAGS",
"ES_EVENT_TYPE_NOTIFY_SETMODE",
"ES_EVENT_TYPE_NOTIFY_SETOWNER",
"ES_EVENT_TYPE_NOTIFY_SETTIME",
"ES_EVENT_TYPE_NOTIFY_TRUNCATE",
"ES_EVENT_TYPE_NOTIFY_UNLINK",
"ES_EVENT_TYPE_NOTIFY_WRITE"
]'

echo "% logging started (file: $logfile)" | tee -a "$logfile"
echo "% using regex: $re" | tee -a "$logfile"

sudo /Applications/FileMonitor.app/Contents/MacOS/FileMonitor -pretty |
jq --raw-output --unbuffered --argjson e "$e_types" --arg re "$re" '
  select(.event? | IN($e[])) |
  select(.file.destination?|match($re)) |
  [ .event, .file.process.name, .file.destination ] |
  @tsv' |
tee -a "$logfile"

Running this script and then creating/updating the xyzzy.txt file at the root of iCloud Drive with common tools like Sublime Text, echo foo >>xyzzy.txt or rm xyzzy.txt produces output like this:

$ poor_mans_fsusage.sh
% logging started (file: /Users/luke/Desktop/FileMonitor.log)
% using regex: ^/Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_CREATE sublime_text    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_WRITE  sublime_text    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_WRITE  bash    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_UNLINK rm  /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_CREATE touch   /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt

However, if I open this file up on my iPhone (using Files.app) and modify it there, a strange thing happens. No ES_EVENT_TYPE_NOTIFY_WRITE events are seen. Yet the file somehow gets updated. It appears that maybe there is some sort of atomic saving going on (temp file saving, moving (renaming) the original, replacing etc. But I can't be sure. Here's a sample of the output:

ES_EVENT_TYPE_NOTIFY_RENAME bird    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_RENAME bird    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_RENAME bird    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt

If I change the filtering to log all NOTIFY_WRITEs, I get a flurry of activity (I de-duped all the log lines below otherwise it would be pages long)

$ sudo /Applications/FileMonitor.app/Contents/MacOS/FileMonitor -pretty |
jq --raw-output --unbuffered --arg re "$re" 'select(.file.destination|test("/dev/")?|not) | select(.event == "ES_EVENT_TYPE_NOTIFY_WRITE") | [ .event, .file.process.name, .file.destination ] | @tsv'

output:

ES_EVENT_TYPE_NOTIFY_WRITE  apsd    /Library/Application Support/ApplePushService/aps.db-wal
ES_EVENT_TYPE_NOTIFY_WRITE  bash    /Users/luke/Library/Mobile Documents/com~apple~CloudDocs/xyzzy.txt
ES_EVENT_TYPE_NOTIFY_WRITE  bird    /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.bird/etilqs_bac799c714aa93e7
ES_EVENT_TYPE_NOTIFY_WRITE  bird    /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.bird/etilqs_cfa75a208c505d56
ES_EVENT_TYPE_NOTIFY_WRITE  bird    /Users/luke/Library/Application Support/CloudDocs/session/db/client.db
ES_EVENT_TYPE_NOTIFY_WRITE  bird    /Users/luke/Library/Application Support/CloudDocs/session/db/server.db-wal
ES_EVENT_TYPE_NOTIFY_WRITE  cloudd  /Users/luke/Library/Caches/CloudKit/CloudKitMetadata-wal
ES_EVENT_TYPE_NOTIFY_WRITE  cloudd  /Users/luke/Library/Caches/CloudKit/com.apple.bird/495ca00354c4d66c9152fd84c120c685b6176ca8/ca7a898f7b8bf12541584d32a8d0f91029e02709/Records/Records.db-wal
ES_EVENT_TYPE_NOTIFY_WRITE  cloudd  /Users/luke/Library/Caches/CloudKit/com.apple.bird/7630364a2c49fa3d5bca30c7cabe73ffa3543026/9fadf220be21a0ed291ebfea5f836e034473cd93/MMCS/.cs/ChunkStoreDatabase-wal
ES_EVENT_TYPE_NOTIFY_WRITE  nehelper    /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/com.apple.nehelper/TemporaryItems/NSIRD_nehelper_7N50R4/com.apple.networkextension.uuidcache.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nehelper    /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/com.apple.nehelper/TemporaryItems/NSIRD_nehelper_Mo766E/com.apple.networkextension.uuidcache.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nehelper    /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/com.apple.nehelper/TemporaryItems/NSIRD_nehelper_SIpEJN/com.apple.networkextension.uuidcache.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_09S10o/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_7dKm3g/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_aRjy8M/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_FbnZNA/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_kqbSoo/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_LCh16g/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_MW3AZz/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_N0NXqe/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_nwGsY9/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_oWboib/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_ox3b2R/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_pT0Uvb/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_tkdjzX/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_u8bI23/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_v3zyFJ/tasks.plist
ES_EVENT_TYPE_NOTIFY_WRITE  nsurlsessiond   /private/var/folders/h6/l1plwtys2yg1wlzspg7cd_n40000gn/T/com.apple.nsurlsessiond/TemporaryItems/NSIRD_nsurlsessiond_xE8v1x/tasks.plist

So it looks like a bunch of other helpers are involved in a simple file update on iCloud. I see nsurlsessiond, cloudd, nehelper... is there any sane way to log this type of activity?

luckman212 commented 3 years ago

leaving this crosspost here as well: Any sane way to log iCloud Drive file activity? - Ask Different

tigersoul925 commented 1 year ago

Just a comment, all those e_types are not logged currently by filemonitor. Just some of them. Check source. Just in csse you were expecting events from permission changes etc.

luckman212 commented 1 year ago

Thanks @tigersoul925 - I'm on Ventura now so there's a built in tool called eslogger that can be used to capture these kinds of events coming through the Endpoint Security log.

tigersoul925 commented 1 year ago

Thanks @tigersoul925 - I'm on Ventura now so there's a built in tool called eslogger that can be used to capture these kinds of events coming through the Endpoint Security log.

Oh wow I was NOT aware of eslogger and it looks great as I potentielly could get updates of permission changes etc as well now which filemonitor does not support.

How is your experience with eslogger? Does it work well? It seems in the man pages that it isn't really meant for true usage:

eslogger is not intended to be used by applications. It is not meant provide the same functionality, performance and schema stability as natively interfacing with the Endpoint Security API does. It cannot provide the integrity protection granted to System Extensions. Applications should continue to interface with EndpointSecurity(7) natively.

luckman212 commented 1 year ago

It's a great tool, has helped me a lot and works fine. I think the warning is to discourage people from lazily forking out to it from inside their apps instead of properly interfacing with the ESF API.

tigersoul925 commented 1 year ago

It's a great tool, has helped me a lot and works fine. I think the warning is to discourage people from lazily forking out to it from inside their apps instead of properly interfacing with the ESF API.

I see. Got to try it soon. Sounds great. Just a shame it didn't appear earlier.