test(android): fix alarm counting logic and add screenshot capture

Fix alarm counting to correctly parse dumpsys output where app ID and
action appear on different lines. Add screenshot capture for test
diagnostics and create golden run documentation.

Test Harness Improvements:
- Fix get_plugin_alarm_count() to track app ID and action separately
  across alarm block lines (fixes false 0-count bug)
- Add show_plugin_alarms_compact() to display complete alarm blocks
- Add wait_for_stable_plugin_alarm_count() polling helper to reduce
  race condition false negatives
- Add take_screenshot() and take_failure_screenshot() helpers for
  automatic test state capture
- Integrate screenshots into TEST 0 at key checkpoints
- Update TEST 0 messaging to handle race conditions gracefully
- Add screenshots/ to .gitignore

Documentation:
- Create PHASE1_TEST0_GOLDEN.md with actual values from successful run
- Document expected script output, UI state, dumpsys shape, and logcat
  patterns
- Include pass/fail checklist for future test runs

This fixes the issue where alarm counting always returned 0 because the
AWK logic required app ID and action on the same line, but dumpsys
output has them on separate lines (header line has app ID, tag line
has action).
This commit is contained in:
Matthew Raymer
2025-12-04 09:28:28 +00:00
parent fc2f64bae3
commit 1103513db3
4 changed files with 476 additions and 28 deletions

View File

@@ -226,6 +226,9 @@ main() {
launch_app
ensure_plugin_configured
# Capture pre-schedule UI state
take_screenshot "phase1_test0_daily_rollover" "before_scheduling"
INITIAL_COUNT=$(get_plugin_alarm_count)
SYSTEM_COUNT=$(get_system_alarm_count)
print_info "Current notification alarms: ${INITIAL_COUNT} (expected before scheduling: 0)"
@@ -243,22 +246,30 @@ main() {
- 1 notification alarm (AlarmManager) for the specified time
- 1 prefetch job (WorkManager) for 2 minutes before that time"
sleep 3 # Give alarm time to be registered in AlarmManager
# Capture post-schedule UI state
take_screenshot "phase1_test0_daily_rollover" "after_scheduling"
POST_SCHEDULE_COUNT=$(get_plugin_alarm_count)
# Check alarm count after scheduling
# Note: 0 alarms is likely a race condition (alarm may not be visible yet in dumpsys)
# Note: This is a PRELIMINARY sanity check only - final verdict comes after rollover
# 0 alarms is likely a race condition (alarm may not be visible yet in dumpsys)
# Only treat >1 alarms as a real failure (duplicates)
if [ "${POST_SCHEDULE_COUNT}" -eq "0" ] 2>/dev/null; then
print_warn "⚠️ Found 0 plugin alarms right after scheduling."
print_info " This is likely a race condition treating as inconclusive, not a failure."
print_info " The alarm may not be visible in dumpsys yet. We'll rely on the rollover check."
print_info " Pre-schedule check not reliable; will rely on rollover assertions."
print_info " The alarm may not be visible in dumpsys yet. Continuing to verify after rollover."
elif [ "${POST_SCHEDULE_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Found 1 notification alarm (expected: 1) immediate post-schedule check passed."
print_success "✅ Found 1 notification alarm (expected: 1) preliminary check passed."
print_info " This is preliminary check only; final verdict after rollover."
else
# count > 1 - this is a real duplicate bug
print_warn "⚠️ ⚠️ Found ${POST_SCHEDULE_COUNT} notification alarms (expected: 1) DUPLICATES DETECTED right after scheduling!"
print_warn "This indicates duplicate NOTIFICATION alarms were created (BUG DETECTED)"
print_info "For debugging, run:"
print_info "Showing alarm blocks for debugging:"
show_plugin_alarms_compact
print_info "For more details, run:"
print_info " adb shell dumpsys alarm | grep -A 5 'com.timesafari.dailynotification' | sed -n '1,80p'"
fi
INITIAL_COUNT="${POST_SCHEDULE_COUNT}"
@@ -316,12 +327,19 @@ main() {
echo " - Prefetch job scheduled in WorkManager"
echo ""
echo "Expected log patterns:"
echo " DNP-PLUGIN: Calculated next run time: cron=<time>"
echo " DNP-SCHEDULE: Scheduling next daily alarm: ... source=ROLLOVER_ON_FIRE"
echo " DNP-NOTIFY: Scheduling alarm: triggerTime=<tomorrow's time>"
echo " DNP-SCHEDULE: Scheduling OS alarm: variant=ALARM_CLOCK, action=com.timesafari.daily.NOTIFICATION, ..."
echo ""
echo "When scheduling the test notification, expect:"
echo " DNP-SCHEDULE: ... source=TEST_NOTIFICATION"
echo ""
echo "Alarm shape in dumpsys:"
echo " RTC_WAKEUP, ALARM_CLOCK, tag=*walarm*:com.timesafari.daily.NOTIFICATION"
echo ""
echo "After notification fires, run:"
echo " adb shell dumpsys alarm | grep -A 3 'com.timesafari.dailynotification'"
echo " adb logcat -d | grep -E 'DNP-PLUGIN|DNP-NOTIFY' | tail -20"
echo " adb logcat -d | grep -E 'DNP-SCHEDULE|DNP-NOTIFY' | tail -20"
echo ""
wait_for_ui_action "After the notification fires (or you advance the clock),
@@ -333,12 +351,16 @@ main() {
Press Enter when you've verified this (or to skip this test)."
POST_ROLLOVER_COUNT=$(get_plugin_alarm_count)
print_info "Polling for stable alarm count (allowing up to ~10 seconds for Android to settle)..."
POST_ROLLOVER_COUNT=$(wait_for_stable_plugin_alarm_count 5 2)
SYSTEM_FINAL=$(get_system_alarm_count)
print_info "Notification alarms after rollover: ${POST_ROLLOVER_COUNT} (expected: 1)"
print_info "System/other alarms: ${SYSTEM_FINAL} (for context)"
print_info "Note: Prefetch is scheduled via WorkManager (not AlarmManager), so it won't appear in alarm count"
# Capture post-rollover UI state
take_screenshot "phase1_test0_daily_rollover" "after_rollover_check"
# After rollover, the state should be stable - this is the real assertion point
if [ "${POST_ROLLOVER_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ TEST 0 PASSED: Daily rollover created exactly one NOTIFICATION alarm for tomorrow."
@@ -348,15 +370,40 @@ main() {
elif [ "${POST_ROLLOVER_COUNT}" -gt "1" ] 2>/dev/null; then
print_warn "⚠️ ⚠️ TEST 0 FAILED: Daily rollover created ${POST_ROLLOVER_COUNT} NOTIFICATION alarms (duplicates)."
print_warn "This indicates duplicate NOTIFICATION alarms were created (BUG DETECTED)"
print_info "For debugging, run:"
print_info " adb shell dumpsys alarm | grep -A 5 'com.timesafari.dailynotification' | sed -n '1,80p'"
take_failure_screenshot "phase1_test0_daily_rollover" "duplicate_alarms"
echo ""
print_info "Showing alarm blocks for debugging:"
show_plugin_alarms_compact
echo ""
print_info "Check scheduling logs for multiple DNP-SCHEDULE entries:"
print_info " adb logcat -d | grep 'DNP-SCHEDULE\|DNP-NOTIFY' | tail -20"
echo ""
print_info "Possible causes:"
echo " - Multiple scheduling paths racing (rollover + recovery)"
echo " - Old alarm wasn't canceled before scheduling new one"
echo " - Different scheduleIds used for same trigger time"
echo " - Idempotence check not working correctly"
else
# count is 0 or invalid - rollover may have failed
print_warn "⚠️ TEST 0 INCONCLUSIVE: No NOTIFICATION alarm found after rollover check logs/dumpsys manually."
print_warn "⚠️ TEST 0 INCONCLUSIVE: No NOTIFICATION alarm found after rollover (expected 1, got 0)"
print_warn "This indicates the rollover did not schedule tomorrow's alarm correctly"
take_failure_screenshot "phase1_test0_daily_rollover" "no_alarm_after_rollover"
echo ""
print_info "Showing alarm blocks for debugging:"
show_plugin_alarms_compact
echo ""
print_info "Expected log pattern after fire:"
echo " DNP-SCHEDULE: Scheduling next daily alarm: ... source=ROLLOVER_ON_FIRE"
echo " DNP-NOTIFY: Scheduling alarm: triggerTime=<tomorrow>"
echo " DNP-SCHEDULE: Scheduling OS alarm: variant=ALARM_CLOCK, action=com.timesafari.daily.NOTIFICATION, ..."
echo ""
print_info "Check logs for rollover scheduling errors:"
print_info " adb logcat -d | grep 'DNP-SCHEDULE\|DNP-NOTIFY' | tail -20"
print_info " adb shell dumpsys alarm | grep -A 3 'com.timesafari.dailynotification'"
echo ""
print_info "Manual verification:"
echo " If dumpsys shows a single RTC_WAKEUP alarm with"
echo " tag=*walarm*:com.timesafari.daily.NOTIFICATION for tomorrow,"
echo " treat TEST 0 as manually PASSED and update the script expectations later."
fi
wait_for_user