also looking at this
fix(ios): settle a Siri shortcut removal whose completion never comes
#227
7 files
+503
-94
| @@ -152,7 +152,10 @@ gather_log() { cat "$STDOUT_LOG" "$STDERR_LOG" > "$LOG" 2>/dev/null || true; } | ||
| 152 | 152 | # So: a deadline, and an explicit failure that names what is missing. The two |
| 153 | 153 | # situations look nothing alike now. |
| 154 | 154 | SLICE_TIMEOUT="${CRAFT_SLICE_TIMEOUT:-600}" |
| 155 | AWAITED_IDS="20 22 24 26 28 32 34 38 44 46 72 76 78 82" | |
| 155 | # `38|84|86` is one wait: the Siri removal settles as its completion, its | |
| 156 | # deadline, or something else, and the assertions below tell them apart. 54 | |
| 157 | # is awaited because openSettings now waits for that removal. | |
| 158 | AWAITED_IDS="20 22 24 26 28 32 34 38|84|86 44 46 54 72 76 78 82" | |
| 156 | 159 | DEADLINE=$(( $(date +%s) + SLICE_TIMEOUT )) |
| 157 | 160 | |
| 158 | 161 | missing_ids() { |
| @@ -162,7 +165,8 @@ missing_ids() { | ||
| 162 | 165 | # ERE with an explicit boundary rather than \b, which is a GNU |
| 163 | 166 | # extension this script cannot count on, and rather than a bare |
| 164 | 167 | # "i=$id", which matches i=260 when it is looking for i=26. |
| 165 | grep -qE "i=$id(\$|[^0-9])" "$LOG" 2>/dev/null || missing="$missing i=$id" | |
| 168 | # Grouped, so an alternation cannot match a bare "84" elsewhere. | |
| 169 | grep -qE "i=($id)(\$|[^0-9])" "$LOG" 2>/dev/null || missing="$missing i=$id" | |
| 166 | 170 | done |
| 167 | 171 | echo "$missing" |
| 168 | 172 | } |
| @@ -181,6 +185,18 @@ while :; do | ||
| 181 | 185 | fi |
| 182 | 186 | sleep 1 |
| 183 | 187 | done |
| 188 | ||
| 189 | # A removal its deadline answered can still be completed later, and when it is, | |
| 190 | # Zig logs how late. Give that line a little while before judging i=84 below, | |
| 191 | # so the report says which it was. | |
| 192 | LATE_PATTERN='a deletion completion arrived [0-9]+ ms after the call' | |
| 193 | if grep -qE "i=84(\$|[^0-9])" "$LOG" 2>/dev/null; then | |
| 194 | for _ in $(seq 1 15); do | |
| 195 | gather_log | |
| 196 | grep -qE "$LATE_PATTERN" "$LOG" 2>/dev/null && break | |
| 197 | sleep 1 | |
| 198 | done | |
| 199 | fi | |
| 184 | 200 | xcrun simctl terminate "$UDID" "$BUNDLE_ID" 2>/dev/null || true |
| 185 | 201 | gather_log |
| 186 | 202 | |
| @@ -359,12 +375,49 @@ C36="$(count 36)" | ||
| 359 | 375 | [ "$C36" -ge 1 ] || { echo "FAIL: registerSiriShortcut did not echo the donated shortcut"; exit 1; } |
| 360 | 376 | echo "ok: NSUserActivity donated and echoed back (i=36 seen ${C36}x)" |
| 361 | 377 | |
| 362 | C38="$(count 38)" | |
| 378 | C38="$(count 38)"; C84="$(count 84)"; C86="$(count 86)" | |
| 363 | 379 | # removeSiriShortcut answers from a void(^)(void) completion that carries no |
| 364 | 380 | # arguments at all, so this reply arriving proves Foundation fired the block |
| 365 | 381 | # and the parked payload was delivered under the right request id. |
| 366 | [ "$C38" -ge 1 ] || { echo "FAIL: the deletion completion never fired, or its reply was lost"; exit 1; } | |
| 367 | echo "ok: argument-free completion block delivered its parked reply (i=38 seen ${C38}x)" | |
| 382 | # | |
| 383 | # The completion comes from a system daemon (#211), and whether it comes is | |
| 384 | # the simulator's business. Locally it lands in tens of milliseconds. On CI's | |
| 385 | # macOS runners, three runs of this fixture saw none at all: not within 75 s in | |
| 386 | # the foreground, and not within 30 s after the app was backgrounded. Before | |
| 387 | # the deadline, the runs that passed did so because openSettings happened to | |
| 388 | # background the app while the call was still waiting. | |
| 389 | # | |
| 390 | # So this asserts what #211 is about, which the app controls: the call | |
| 391 | # settles. i=38 is the completion; i=84 is the 15 s deadline answering TIMEOUT | |
| 392 | # instead of the page waiting for ever, which passes with a warning that the | |
| 393 | # completion path went unexercised on this run. What that path needs from Zig | |
| 394 | # (a global block per call, and exactly one answer when it races the deadline) | |
| 395 | # is covered by bridge_mobile_siri.zig's host tests, and any run where the | |
| 396 | # simulator does call it, as it does locally, still goes through i=38. | |
| 397 | # | |
| 398 | # Settling twice is caught here only when both answers land before the app is | |
| 399 | # backgrounded, which is rare by construction: the Zig host tests in | |
| 400 | # bridge_mobile_siri.zig are what guard "exactly one answer". This is a cheap | |
| 401 | # extra look, not that guarantee. | |
| 402 | SIRI_KINDS=$(( (C38 > 0) + (C84 > 0) + (C86 > 0) )) | |
| 403 | if [ "$SIRI_KINDS" -ge 2 ]; then | |
| 404 | echo "FAIL: removeSiriShortcut settled more than one way (i=38 ${C38}x, i=84 ${C84}x, i=86 ${C86}x)" | |
| 405 | exit 1 | |
| 406 | elif [ "$C38" -ge 1 ]; then | |
| 407 | echo "ok: argument-free completion block delivered its parked reply (i=38 seen ${C38}x)" | |
| 408 | elif [ "$C84" -ge 1 ]; then | |
| 409 | LATE="$(grep -oE "$LATE_PATTERN" "$PLAIN" | head -1 || true)" | |
| 410 | echo "ok: removeSiriShortcut settled with TIMEOUT from its native deadline instead of hanging (i=84 seen ${C84}x)" | |
| 411 | NOTE="the simulator never called the NSUserActivity deletion completion, so this run did not exercise that path" | |
| 412 | [ -n "$LATE" ] && NOTE="the simulator called the NSUserActivity deletion completion only after the deadline (${LATE}), and it was ignored" | |
| 413 | echo "note: $NOTE" | |
| 414 | # A GitHub annotation, so an unexercised path shows on the run page rather | |
| 415 | # than only in the log. | |
| 416 | if [ -n "${GITHUB_ACTIONS:-}" ]; then echo "::warning title=removeSiriShortcut completion::$NOTE"; fi | |
| 417 | else | |
| 418 | echo "FAIL: removeSiriShortcut settled with neither {removed: true} nor TIMEOUT (i=86 seen ${C86}x)" | |
| 419 | exit 1 | |
| 420 | fi | |
| 368 | 421 | |
| 369 | 422 | C46="$(count 46)" |
| 370 | 423 | # pageCount is PDFKit's answer for the bytes the page sent, so it cannot be |