Requesting `symlink_target` breaks queries & subscriptions on symlink deletion

Issue

Requesting the symlink_target field causes Watchman to fail to respond to queries, or send unilateral subscription notifications, where the response would include a deleted symlink. A subscription enters a zombie state and never sends any further notifications. A query hangs the client.

This can be reproduced by deleting a symlink and performing a "since" query with a pre-deletion clock.

(Reporting this on GitHub to provide an OSS reference point for Metro etc)

Environment

Version: 20221208

Working: ✅ Eden on macOS (reports symlink_target: null after deletion)

Not working: ❌ kqueue+fsevents on macOS ❌ fsevents on macOS ❌ inotify on Linux ❌ win32 on Windows (Watchman 20220918.223204.0 from Choco)

watchman-diag (macOS): P587187472

Reproduction script

(requires jq to parse a clock out of the initial query)

#! /bin/sh

WATCH_ROOT="$TMPDIR/watchman-symlink-deletion"

rm -r "$WATCH_ROOT"
mkdir "$WATCH_ROOT"

REQUEST_FIELDS='["name", "exists"]'
if [ "$SYMLINKS" == "1" ]
then
    REQUEST_FIELDS='["name", "exists", "symlink_target"]'
fi

echo "Working in $WATCH_ROOT"
echo '{}' > "$WATCH_ROOT/.watchmanconfig"
ln -s  "any-target" "$WATCH_ROOT/my-link"

watchman watch-project "$WATCH_ROOT"

INITIAL_RESULT=$(watchman -j --server-encoding=json <<-EOF
["query", "$WATCH_ROOT", {
  "fields": ["name", "exists"]
}]
EOF
)
CLOCK=$(echo "$INITIAL_RESULT" | jq '.clock');

echo "Symlink exists at: $CLOCK"

echo "Deleting symlink"
rm "$WATCH_ROOT/my-link"

echo "Performing since query (fields=$REQUEST_FIELDS)"
watchman -j --server-encoding=json <<-EOF
["query", "$WATCH_ROOT", {
  "since": $CLOCK,
  "fields": $REQUEST_FIELDS
}]
EOF

echo "Success";

Output

`SYMLINKS=1 ./watchman-query-test.sh` (broken)

Working in /var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T//watchman-symlink-deletion
{
    "version": "20221208",
    "watcher": "kqueue+fsevents",
    "watch": "/private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion"
}
Symlink exists at: "c:1671045928:15784:280:3"
Deleting symlink
Performing since query (fields=["name", "exists", "symlink_target"])

Process hangs

`SYMLINKS=0 ./watchman-query-test.sh` (working)

SYMLINKS=0 /bin/sh ./watchman-query-test.sh
Working in /var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T//watchman-symlink-deletion
{
    "version": "20221208",
    "watcher": "kqueue+fsevents",
    "watch": "/private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion"
}
Symlink exists at: "c:1671045928:15784:281:3"
Deleting symlink
Performing since query (fields=["name", "exists"])
{
    "version": "20221208",
    "files": [
        {
            "name": "my-link",
            "exists": false
        }
    ],
    "is_fresh_instance": false,
    "clock": "c:1671045928:15784:281:6",
    "debug": {
        "cookie_files": [
            "/private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion/.watchman-cookie-robhogan-mbp-15784-1"
        ]
    }
}
Success

Log output

2022-12-28T11:37:44,992: [client=18473:stm=105553687604224:pid=79233] path /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion is on filesystem type apfs
2022-12-28T11:37:45,007: [client=18473:stm=105553687604224:pid=79233] failed to use watcher eden: apfs is not a FUSE file system.
2022-12-28T11:37:45,007: [client=18473:stm=105553687604224:pid=79233] root /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion using watcher mechanism kqueue+fsevents (auto was requested)
2022-12-28T11:37:45,008: [io 140281709287592 /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion] failed to open /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion/my-link, O_EVTONLY: No such file or directory
2022-12-28T11:37:45,008: [io 140281709287592 /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion] PERF: {"user_time": 0.00014999999999999999, "start_time": 1672227465.0081799, "elapsed_time": 0.00031500000000000001, "version": "20221208", "system_time": 0.00038900000000000002, "meta": {"root": {"recrawl_count": 0, "case_sensitive": false, "watcher": "kqueue+fsevents", "path": "/private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion"}}, "pid": 15784, "description": "full-crawl"}
2022-12-28T11:37:45,008: [io 140281709287592 /private/var/folders/f6/jkxrp7ms5f92b62wkbn369qw0000gn/T/watchman-symlink-deletion] crawl complete

This output is generated during the initial query. There is no log output generated during the "since" query.

facebook / watchman