daily-notification-plugin/docs/prefetch-scheduling-trace.md

Prefetch Scheduling Trace Analysis

Analysis Date: October 27, 2025 - 12:18:37 UTC
Author: Matthew Raymer
Status: Investigation Complete

Summary

This document traces how prefetch scheduling works solo and in conjunction with notification schedules. Investigation reveals that prefetch schedules ARE being set, but there may be issues with logging visibility and execution.

Code Flow Analysis

1. Notification Scheduling Flow

When a user schedules a notification via the plugin:

DailyNotificationPlugin.scheduleDailyNotification()
  ↓
  DailyNotificationScheduler.scheduleNotification()
  ↓
  Plugin.scheduleBackgroundFetch(content.getScheduledTime())

Location: android/plugin/src/main/java/com/timesafari/dailynotification/DailyNotificationPlugin.java:658

2. Prefetch Scheduling Flow

The scheduleBackgroundFetch method calculates the fetch time:

private void scheduleBackgroundFetch(long scheduledTime) {
    try {
        Log.d(TAG, "DN|SCHEDULE_FETCH_START time=" + scheduledTime);
        
        // Schedule fetch 5 minutes before notification
        long fetchTime = scheduledTime - TimeUnit.MINUTES.toMillis(5);
        
        if (fetchTime > System.currentTimeMillis()) {
            Log.d(TAG, "DN|SCHEDULE_FETCH_CALC fetch_at=" + fetchTime + " notification_at=" + scheduledTime);
            fetcher.scheduleFetch(fetchTime);
            Log.i(TAG, "DN|SCHEDULE_FETCH_OK Background fetch scheduled for " + fetchTime + " (5 minutes before notification at " + scheduledTime + ")");
        } else {
            Log.w(TAG, "DN|SCHEDULE_FETCH_PAST fetch_time=" + fetchTime + " current=" + System.currentTimeMillis());
        }
    } catch (Exception e) {
        Log.e(TAG, "DN|SCHEDULE_FETCH_ERR Error scheduling background fetch", e);
    }
}

Location: DailyNotificationPlugin.java:961-978

3. WorkManager Enqueuing

The fetcher.scheduleFetch() method creates a WorkManager request:

public void scheduleFetch(long scheduledTime) {
    try {
        Log.d(TAG, "Scheduling background fetch for " + scheduledTime);
        
        // Calculate fetch time (5 minutes before notification)
        long fetchTime = scheduledTime - TimeUnit.MINUTES.toMillis(5);
        
        if (fetchTime > System.currentTimeMillis()) {
            // Create work data
            Data inputData = new Data.Builder()
                .putLong("scheduled_time", scheduledTime)
                .putLong("fetch_time", fetchTime)
                .putInt("retry_count", 0)
                .build();
            
            // Create one-time work request
            OneTimeWorkRequest fetchWork = new OneTimeWorkRequest.Builder(
                DailyNotificationFetchWorker.class)
                .setInputData(inputData)
                .addTag(WORK_TAG_FETCH)
                .setInitialDelay(fetchTime - System.currentTimeMillis(), TimeUnit.MILLISECONDS)
                .build();
            
            // Enqueue the work
            workManager.enqueue(fetchWork);
            
            Log.i(TAG, "Background fetch scheduled successfully");
            
        } else {
            Log.w(TAG, "Fetch time has already passed, scheduling immediate fetch");
            scheduleImmediateFetch();
        }
        
    } catch (Exception e) {
        Log.e(TAG, "Error scheduling background fetch", e);
        // Fallback to immediate fetch
        scheduleImmediateFetch();
    }
}

Location: DailyNotificationFetcher.java:77-115

Key Findings

✅ Prefetch Scheduling IS Implemented

The code shows that:

1. When a notification is scheduled, scheduleBackgroundFetch() is called if scheduling succeeds
2. The prefetch time is calculated: fetchTime = scheduledTime - 5 minutes
3. WorkManager work is enqueued with the calculated delay
4. Logs ARE generated at several points

⚠️ Potential Issues

1. Logging Visibility

   • Logs may not be visible if:
     • The app is closed (logs go to system logcat)
     • Filters are not capturing the right tags
     • Log level is not set correctly

2. Conditional Logging

   • The scheduleBackgroundFetch is only called when scheduled == true
   • If notification scheduling fails, no prefetch is scheduled
   • This is at line 655-666 in DailyNotificationPlugin.java

3. Timing Issues

   • If fetchTime is in the past, it schedules immediate fetch
   • This might cause confusion if timing calculations are wrong

Expected Log Sequence

When properly scheduling a notification:

DN|SCHEDULE_CALLBACK scheduled=true, calling scheduleBackgroundFetch
DN|SCHEDULE_FETCH_START time=<scheduledTime>
DN|SCHEDULE_FETCH_CALC fetch_at=<fetchTime> notification_at=<scheduledTime>
Scheduling background fetch for <scheduledTime>
Background fetch scheduled successfully
DN|SCHEDULE_FETCH_OK Background fetch scheduled for <fetchTime> (5 minutes before notification at <scheduledTime>)

How to Debug

1. Check if Prefetch is Being Scheduled

Look for these log tags in logcat:

adb logcat | grep -E "DN\|SCHEDULE_FETCH|DailyNotificationFetcher"

Expected logs:

• DN|SCHEDULE_FETCH_START
• DN|SCHEDULE_FETCH_CALC
• DN|SCHEDULE_FETCH_OK
• Scheduling background fetch for

2. Check WorkManager Queue

Verify that work is actually enqueued:

adb shell dumpsys job scheduler | grep -A 5 "daily_notification_fetch"

3. Check if Notification Scheduling Succeeded

Verify the notification scheduling succeeded (this is a prerequisite):

adb logcat | grep "DN|SCHEDULE"

Look for:

• DN|SCHEDULE_CALLBACK scheduled=true - Good, prefetch will be scheduled
• DN|SCHEDULE_CALLBACK scheduled=false - Bad, prefetch will NOT be scheduled

4. Check AlarmManager Schedule

Verify the actual alarm is set:

adb shell dumpsys alarm | grep -i "dailynotification"

Investigation Checklist

To diagnose why prefetch logs aren't appearing:

• Check if notification scheduling is succeeding (look for DN|SCHEDULE_CALLBACK scheduled=true)
• Check if scheduleBackgroundFetch is being called (look for DN|SCHEDULE_FETCH_START)
• Check if fetch time calculation is correct (look for DN|SCHEDULE_FETCH_CALC)
• Check if WorkManager is enqueuing the work (look for "Background fetch scheduled successfully")
• Check if fetch time is in the past (look for "Fetch time has already passed")
• Check WorkManager queue status via dumpsys job scheduler
• Check for any exceptions (look for "DN|SCHEDULE_FETCH_ERR" or "Error scheduling background fetch")

Recommendations

1. Add More Diagnostic Logging

Add logs at critical decision points:

// In scheduleDailyNotification, after scheduler.scheduleNotification()
if (scheduled) {
    Log.i(TAG, "DN|SCHEDULE_CALLBACK scheduled=true, calling scheduleBackgroundFetch");
    Log.d(TAG, "DN|SCHEDULE_CALLBACK content.getScheduledTime()=" + content.getScheduledTime());
    scheduleBackgroundFetch(content.getScheduledTime());
} else {
    Log.w(TAG, "DN|SCHEDULE_CALLBACK scheduled=false, NOT calling scheduleBackgroundFetch");
}

2. Add WorkManager Status Logging

Add a log after enqueuing to verify:

workManager.enqueue(fetchWork);
Log.i(TAG, "DN|SCHEDULE_WORK_ENQUEUED work_id=" + fetchWork.getId() + 
          " fetch_at=" + fetchTime + " delay_ms=" + (fetchTime - System.currentTimeMillis()));

3. Add User-Zero Specific Logging

For stars querying, add specific event IDs:

Log.i(TAG, "EVT_PREFETCH_SCHEDULED time=" + fetchTime + " stars_query=true");

Next Steps

1. Capture logcat during notification scheduling
2. Search for specific log prefixes documented above
3. Check WorkManager queue to verify work is enqueued
4. Add diagnostic logging if needed
5. Test with actual notification scheduling to see full flow

Conclusion

The prefetch scheduling IS implemented in the codebase. The issue is likely one of:

• Logging visibility (logs not being captured)
• Timing issues (fetch time in past)
• Notification scheduling failure (prefetch not called)
• WorkManager not executing (system-level issue)

The infrastructure is there, but we need to verify the execution path.