trent_larson/daily-notification-plugin
4
0
Fork 0
Code Issues Pull Requests 2 Projects Releases Wiki Activity

fix(notify): eliminate duplicate alarm scheduling and fix test harness counting

Browse Source 
Centralize all notification alarm scheduling through NotifyReceiver.scheduleExactNotification()
with idempotence checks to prevent duplicate alarms. Implement one-alarm policy using
setAlarmClock() only. Fix test harness alarm counting to deduplicate by Alarm handle.

Plugin Changes:
- Add ScheduleSource enum to track scheduling paths (INITIAL_SETUP, ROLLOVER_ON_FIRE, etc.)
- Add DB-level idempotence check before scheduling (prevents logical duplicates)
- Add explicit alarm cancellation before scheduling (safety net)
- Implement one-alarm policy: use setAlarmClock() only, no setExact* fallbacks for same event
- Add deep logging for all AlarmManager calls (variant, requestCode, pendingIntentHash)
- Update all rollover paths (DailyNotificationReceiver, DailyNotificationWorker) to use
  centralized function with ROLLOVER_ON_FIRE source
- Add @JvmStatic annotation to scheduleExactNotification for Java interop

Test Harness Changes:
- Fix get_plugin_alarm_count() to deduplicate by Alarm handle (prevents double-counting
  same alarm in main list and "Next wake from idle" section)
- Update TEST 0 messaging: treat 0 alarms as race condition (inconclusive, not failure)
- Make post-rollover check the authoritative assertion point (only fails on >1 or 0 alarms)
- Remove redundant "Found 0 alarms - test may not be accurate" messages

This fixes the duplicate alarm bug where two distinct AlarmManager entries were created
for the same daily notification, violating the "one notification per day" contract.
This commit is contained in:
Matthew Raymer
2025-12-01 10:09:54 +00:00
parent ba8f98db65
commit fc2f64bae3
13 changed files with 880 additions and 186 deletions
Download Patch File Download Diff File Expand all files Collapse all files

284
test-apps/android-test-app/test-phase1.sh
View File

@@ -197,6 +197,171 @@ main() {
# Clear logs
clear_logs
# ============================================
# TEST 0: Daily Rollover (Core Contract Verification)
# ============================================
# Note: This test verifies the core "one notification per day" contract
# by checking that after a notification fires, the next day's schedule
# is correctly computed and scheduled. This is a manual/semi-automated test
# as it requires either waiting for the alarm to fire or manipulating time.
#
# To run: Use test ID "0" or enable manually
# ============================================
if should_run_test "0" SELECTED_TESTS; then
print_header "TEST 0: Daily Rollover Verification"
echo "Purpose: Verify that after a notification fires, the next day's"
echo " schedule is correctly computed and only ONE alarm exists."
echo ""
echo "Note: This test verifies the core 'one notification per day' contract."
echo " It requires either:"
echo " 1. Scheduling a notification for 'now + N seconds' and waiting, OR"
echo " 2. Manipulating the emulator clock to cross the fire boundary."
echo ""
echo " For now, this is a MANUAL test - you'll need to verify the"
echo " behavior by checking logs and AlarmManager after a notification fires."
echo ""
wait_for_user
print_step "1" "Schedule a test notification for near-future (or use existing)..."
launch_app
ensure_plugin_configured
INITIAL_COUNT=$(get_plugin_alarm_count)
SYSTEM_COUNT=$(get_system_alarm_count)
print_info "Current notification alarms: ${INITIAL_COUNT} (expected before scheduling: 0)"
print_info "System/other alarms: ${SYSTEM_COUNT} (for context)"
print_info "Note: Prefetch uses WorkManager (not AlarmManager), so it won't appear in alarm count"
if [ "${INITIAL_COUNT}" -eq "0" ] 2>/dev/null; then
print_success "✅ No existing notification alarms (clean state)"
wait_for_ui_action "In the app UI, schedule a daily notification.
For this test, you may want to schedule it for a time very soon
(e.g., 1-2 minutes from now) to observe the rollover behavior.
This will schedule:
- 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
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)
# 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."
elif [ "${POST_SCHEDULE_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Found 1 notification alarm (expected: 1) – immediate post-schedule check passed."
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 " adb shell dumpsys alarm | grep -A 5 'com.timesafari.dailynotification' | sed -n '1,80p'"
fi
INITIAL_COUNT="${POST_SCHEDULE_COUNT}"
fi
# Only show alarm details if we found exactly 1 alarm (skip if 0 due to race condition)
if [ "${INITIAL_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single notification alarm scheduled (one per day)"
print_info "Note: Prefetch uses WorkManager (not AlarmManager), so it won't appear in alarm count"
# Show alarm details
ALARM_DETAILS=$($ADB_BIN shell dumpsys alarm | grep -A 3 "com.timesafari.dailynotification" | grep -A 3 "com.timesafari.daily.NOTIFICATION" | head -10)
if [ -n "${ALARM_DETAILS}" ]; then
print_info "Notification alarm details:"
echo "${ALARM_DETAILS}" | head -5
echo ""
# Extract trigger time
ALARM_TRIGGER_MS=$(echo "${ALARM_DETAILS}" | grep -oE "origWhen [0-9]+" | head -1 | awk '{print $2}')
if [ -n "${ALARM_TRIGGER_MS}" ]; then
ALARM_TRIGGER_SEC=$((ALARM_TRIGGER_MS / 1000))
ALARM_READABLE=$(date -d "@${ALARM_TRIGGER_SEC}" 2>/dev/null || echo "${ALARM_TRIGGER_MS} ms")
print_info "Notification alarm scheduled for: ${ALARM_READABLE}"
# Calculate prefetch time (2 minutes before)
PREFETCH_SEC=$((ALARM_TRIGGER_SEC - 120))
PREFETCH_READABLE=$(date -d "@${PREFETCH_SEC}" 2>/dev/null || echo "${PREFETCH_SEC}")
print_info "Prefetch should be scheduled for: ${PREFETCH_READABLE} (2 minutes before, via WorkManager)"
# Calculate next day
NEXT_DAY_SEC=$((ALARM_TRIGGER_SEC + 86400))
NEXT_DAY_READABLE=$(date -d "@${NEXT_DAY_SEC}" 2>/dev/null || echo "${NEXT_DAY_SEC}")
print_info "Expected next day notification: ${NEXT_DAY_READABLE} (24 hours later)"
fi
fi
elif [ "${INITIAL_COUNT}" -gt "1" ] 2>/dev/null; then
print_warn "⚠️ Found ${INITIAL_COUNT} notification alarms (expected: 1) - DUPLICATES DETECTED!"
print_warn "This indicates the duplicate alarm bug - multiple alarms for the same notification"
fi
# Note: We intentionally don't print anything for INITIAL_COUNT == 0 here
# because we already handled it above with the race condition message
print_step "2" "Manual verification steps..."
echo ""
echo "To complete this test, you need to:"
echo " 1. Wait for the notification to fire (or advance emulator clock)"
echo " 2. Check that the plugin:"
echo " - Computed the next day's time (24 hours later)"
echo " - Scheduled exactly ONE notification alarm (AlarmManager) for tomorrow"
echo " - Scheduled exactly ONE prefetch job (WorkManager) for 2 minutes before tomorrow's notification"
echo " - Did NOT create duplicate notification alarms"
echo " 3. Verify in logs:"
echo " - Next run time calculation shows tomorrow's time"
echo " - Only one notification alarm scheduled in AlarmManager"
echo " - Prefetch job scheduled in WorkManager"
echo ""
echo "Expected log patterns:"
echo " DNP-PLUGIN: Calculated next run time: cron=<time>"
echo " DNP-NOTIFY: Scheduling alarm: triggerTime=<tomorrow's time>"
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 ""
wait_for_ui_action "After the notification fires (or you advance the clock),
check the logs and AlarmManager to verify:
1. Only ONE alarm exists (one per day)
2. The alarm time is for tomorrow (24 hours later)
3. No duplicate alarms were created
Press Enter when you've verified this (or to skip this test)."
POST_ROLLOVER_COUNT=$(get_plugin_alarm_count)
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"
# 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."
print_info "Expected state after rollover:"
echo " ✅ 1 notification alarm (AlarmManager) for tomorrow"
echo " ✅ 1 prefetch job (WorkManager) for 2 minutes before tomorrow's notification"
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'"
print_info " adb logcat -d | grep 'DNP-SCHEDULE\|DNP-NOTIFY' | tail -20"
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_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'"
fi
wait_for_user
fi
# ============================================
# TEST 1: Force-Stop Recovery - Database Restoration
# ============================================
@@ -220,13 +385,16 @@ main() {
# Step 1: Clean start - verify no lingering alarms
# ============================================
print_step "1" "Clean start - checking for lingering alarms..."
LINGERING_COUNT=$(count_alarms)
LINGERING_COUNT=$(get_plugin_alarm_count)
SYSTEM_COUNT=$(get_system_alarm_count)
if [ "${LINGERING_COUNT}" -gt "0" ] 2>/dev/null; then
print_warn "Found ${LINGERING_COUNT} lingering alarm(s) - these may interfere with test"
print_warn "Found ${LINGERING_COUNT} lingering plugin alarm(s) - these may interfere with test"
print_info "System/other alarms: ${SYSTEM_COUNT} (for context)"
print_info "Consider uninstalling/reinstalling app for clean state"
wait_for_user
else
print_success "No lingering alarms found (clean state)"
print_success "No lingering plugin alarms found (clean state)"
print_info "System/other alarms: ${SYSTEM_COUNT} (for context)"
fi
# ============================================
@@ -246,22 +414,28 @@ main() {
print_step "3" "Verifying alarm exists in AlarmManager (BEFORE force-stop)..."
sleep 2
ALARM_COUNT_BEFORE=$(count_alarms)
print_info "Alarm count in AlarmManager: ${ALARM_COUNT_BEFORE}"
ALARM_COUNT_BEFORE=$(get_plugin_alarm_count)
SYSTEM_COUNT_BEFORE=$(get_system_alarm_count)
print_info "Plugin alarms: ${ALARM_COUNT_BEFORE} (expected: 1)"
print_info "System/other alarms: ${SYSTEM_COUNT_BEFORE} (for context)"
if [ "${ALARM_COUNT_BEFORE}" -eq "0" ] 2>/dev/null; then
print_error "No alarms found in AlarmManager - cannot test force-stop recovery"
print_error "No plugin alarms found in AlarmManager - cannot test force-stop recovery"
print_info "Make sure you clicked 'Test Notification' and wait a moment"
wait_for_user
# Re-check
ALARM_COUNT_BEFORE=$(count_alarms)
ALARM_COUNT_BEFORE=$(get_plugin_alarm_count)
if [ "${ALARM_COUNT_BEFORE}" -eq "0" ] 2>/dev/null; then
print_error "Still no alarms found - aborting test"
exit 1
fi
fi
print_success "✅ Alarms confirmed in AlarmManager (count: ${ALARM_COUNT_BEFORE})"
if [ "${ALARM_COUNT_BEFORE}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single plugin alarm confirmed in AlarmManager (one per day)"
else
print_warn "⚠️ Found ${ALARM_COUNT_BEFORE} plugin alarms (expected: 1) - continuing anyway"
fi
# Capture alarm details for later verification
ALARM_DETAILS_BEFORE=$($ADB_BIN shell dumpsys alarm | grep -A 3 "$APP_ID" | head -10)
@@ -299,14 +473,16 @@ main() {
# ============================================
print_step "5" "Verifying alarms are MISSING from AlarmManager (AFTER force-stop)..."
sleep 1
ALARM_COUNT_AFTER=$(count_alarms)
print_info "Alarm count in AlarmManager after force-stop: ${ALARM_COUNT_AFTER}"
ALARM_COUNT_AFTER=$(get_plugin_alarm_count)
SYSTEM_COUNT_AFTER=$(get_system_alarm_count)
print_info "Plugin alarms after force-stop: ${ALARM_COUNT_AFTER} (expected: 0)"
print_info "System/other alarms: ${SYSTEM_COUNT_AFTER} (for context)"
if [ "${ALARM_COUNT_AFTER}" -eq "0" ] 2>/dev/null; then
print_success "✅ Alarms cleared by force-stop (count: ${ALARM_COUNT_AFTER})"
print_success "✅ Plugin alarms cleared by force-stop (count: ${ALARM_COUNT_AFTER})"
print_info "This confirms: Force-stop cleared alarms from AlarmManager"
else
print_warn "⚠️ Alarms still present after force-stop (count: ${ALARM_COUNT_AFTER})"
print_warn "⚠️ Plugin alarms still present after force-stop (count: ${ALARM_COUNT_AFTER})"
print_info "Some devices/OS versions may not clear alarms on force-stop"
print_info "Continuing test anyway - recovery should still work"
fi
@@ -326,8 +502,10 @@ main() {
# ============================================
print_step "7" "Verifying recovery rebuilt alarms from database..."
sleep 2
ALARM_COUNT_RECOVERED=$(count_alarms)
print_info "Alarm count in AlarmManager after recovery: ${ALARM_COUNT_RECOVERED}"
ALARM_COUNT_RECOVERED=$(get_plugin_alarm_count)
SYSTEM_COUNT_RECOVERED=$(get_system_alarm_count)
print_info "Plugin alarms after recovery: ${ALARM_COUNT_RECOVERED} (expected: 1)"
print_info "System/other alarms: ${SYSTEM_COUNT_RECOVERED} (for context)"
print_info "Checking recovery logs..."
check_recovery_logs
@@ -443,40 +621,64 @@ main() {
fi
# ============================================
# TEST 2: Future Alarm Verification
# TEST 2: Schedule Update (One-Per-Day Semantics)
# ============================================
if should_run_test "2" SELECTED_TESTS; then
print_header "TEST 2: Future Alarm Verification"
echo "Purpose: Verify future alarms are verified/rescheduled if missing."
print_header "TEST 2: Schedule Update Verification"
echo "Purpose: Verify that updating the schedule time maintains 'one per day' semantics."
echo ""
echo "Note: This test verifies that recovery correctly handles multiple alarms."
echo " We'll schedule a second alarm to test recovery with multiple schedules."
echo "Note: This test verifies that when the schedule time changes, the old alarm"
echo " is canceled and only the new one remains (one notification per day)."
echo ""
wait_for_user
print_step "1" "Launch app"
print_step "1" "Launch app and verify initial schedule"
launch_app
ensure_plugin_configured
wait_for_ui_action "In the app UI, click 'Test Notification' to schedule a SECOND notification.
# Get initial alarm count
INITIAL_ALARM_COUNT=$(get_plugin_alarm_count)
SYSTEM_ALARM_COUNT=$(get_system_alarm_count)
print_info "Plugin alarms: ${INITIAL_ALARM_COUNT} (expected: 1)"
print_info "System/other alarms: ${SYSTEM_ALARM_COUNT} (for context)"
This creates an additional scheduled notification (you should now have 2 total).
This tests recovery behavior when multiple alarms exist in the database."
if [ "${INITIAL_ALARM_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Initial alarm confirmed (one per day)"
elif [ "${INITIAL_ALARM_COUNT}" -eq "0" ] 2>/dev/null; then
print_warn "⚠️ No initial alarm found - scheduling one first..."
wait_for_ui_action "In the app UI, schedule a daily notification (e.g., click 'Test Notification')."
sleep 2
INITIAL_ALARM_COUNT=$(get_plugin_alarm_count)
if [ "${INITIAL_ALARM_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Alarm scheduled"
else
print_error "Failed to schedule initial alarm"
wait_for_user
fi
else
print_warn "⚠️ Found ${INITIAL_ALARM_COUNT} plugin alarms (expected: 1) - continuing anyway"
fi
print_step "2" "Verifying alarms are scheduled..."
sleep 2
print_step "2" "Updating schedule time"
wait_for_ui_action "In the app UI, change the schedule time (e.g., from 06:50 to 07:10)
and apply the schedule.
This should cancel the old alarm and schedule a new one at the new time.
You should still have exactly 1 alarm (one per day)."
sleep 3
check_alarm_status
ALARM_COUNT=$(count_alarms)
print_info "Found ${ALARM_COUNT} scheduled alarm(s) (expected: 1)"
UPDATED_ALARM_COUNT=$(get_plugin_alarm_count)
print_info "Plugin alarms after update: ${UPDATED_ALARM_COUNT} (expected: 1)"
if [ "${ALARM_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single alarm confirmed in AlarmManager"
elif [ "${ALARM_COUNT}" -gt "1" ] 2>/dev/null; then
print_success "Alarms are scheduled in AlarmManager"
if [ "${UPDATED_ALARM_COUNT}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single alarm confirmed after schedule update (one per day maintained)"
else
print_error "No alarms found in AlarmManager"
wait_for_user
print_warn "⚠️ Found ${UPDATED_ALARM_COUNT} plugin alarms (expected: 1)"
if [ "${UPDATED_ALARM_COUNT}" -gt "1" ] 2>/dev/null; then
print_warn "⚠️ Multiple alarms detected - old alarm may not have been canceled"
fi
fi
print_step "3" "Killing app and relaunching (triggers recovery)..."
@@ -502,18 +704,22 @@ main() {
VERIFIED_COUNT=$(echo "${RECOVERY_RESULT}" | grep -oE "verified=[0-9]+" | grep -oE "[0-9]+" || echo "0")
# Verify alarm count after recovery
ALARM_COUNT_AFTER_RECOVERY=$(count_alarms)
print_info "Alarm count after recovery: ${ALARM_COUNT_AFTER_RECOVERY} (expected: 1)"
ALARM_COUNT_AFTER_RECOVERY=$(get_plugin_alarm_count)
print_info "Plugin alarms after recovery: ${ALARM_COUNT_AFTER_RECOVERY} (expected: 1)"
if [ "${RESCHEDULED_COUNT}" -gt "0" ] 2>/dev/null; then
print_success "✅ TEST 2 PASSED: Missing future alarm was detected and rescheduled (rescheduled=${RESCHEDULED_COUNT})!"
print_success "✅ TEST 2 PASSED: Missing alarm was detected and rescheduled (rescheduled=${RESCHEDULED_COUNT})!"
if [ "${ALARM_COUNT_AFTER_RECOVERY}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single alarm confirmed in AlarmManager after recovery"
print_success "✅ Single alarm confirmed after recovery (one per day maintained)"
else
print_warn "⚠️ Alarm count is ${ALARM_COUNT_AFTER_RECOVERY} (expected: 1)"
fi
elif [ "${VERIFIED_COUNT}" -gt "0" ] 2>/dev/null; then
print_success "✅ TEST 2 PASSED: Future alarm verified in AlarmManager (verified=${VERIFIED_COUNT})!"
print_success "✅ TEST 2 PASSED: Alarm verified in AlarmManager (verified=${VERIFIED_COUNT})!"
if [ "${ALARM_COUNT_AFTER_RECOVERY}" -eq "1" ] 2>/dev/null; then
print_success "✅ Single alarm confirmed in AlarmManager after recovery"
print_success "✅ Single alarm confirmed after recovery (one per day maintained)"
else
print_warn "⚠️ Alarm count is ${ALARM_COUNT_AFTER_RECOVERY} (expected: 1)"
fi
elif [ "${RESCHEDULED_COUNT}" -eq "0" ] 2>/dev/null && [ "${VERIFIED_COUNT}" -eq "0" ] 2>/dev/null; then
print_warn "⚠️ TEST 2: No verification/rescheduling needed (both verified=0 and rescheduled=0)"