1. Are you ready for the Galaxy S20? Here is everything we know so far!

PeriodicWorkRequest (work v1.0.1) is spawning 20 times every 15m in stead of just once, not sure why

Discussion in 'Android Development' started by Damon Getsman, Nov 7, 2020.

  1. Damon Getsman

    Damon Getsman Newbie
    Thread Starter

    In the follow code excerpts, I am utilizing a BroadcastReceiver to start up a Service on device boot and/or package reload. This NotificationService is calling my Worker via PeriodicWorkRequest every fifteen minutes. Everything initially works as it is supposed to, until the NotificationWorker is executed. It seems that, at the point where the Worker is invoked, it runs twenty times instead of just once. I believe that is twenty times exactly, as well. After all of it is said and done, it waits for ~15 minutes, as it should, and then exhibits the same behavior when it again invokes the Worker. Ideally this Worker should only be run once every 15m, especially being as some of the computation that it will be doing is rather expensive.

    I have spent days now, googling for more information (I've partially been hampered in this due to using Work v1.0.1, instead of the more recent, androidx v2.4.0, but I'm not ready to upgrade everything that would be broken in my project with that change) and doing my best to debug this issue. Unfortunately, the debugging has been rather slow and unproductive, due to the fact that I can rarely get my Log.?() messages to even show up, let alone to give me any hints as to where this behavior is coming from. This behavior (Log messages not showing up) has been a problem in BootServiceStart, NotificationWorker, and NotificationService, and I've got no idea why.

    Here is the applicable code for the issue; please note that if you follow the dpaste links you will find the general areas of the problematic code highlighted in order to ease diagnosis a bit (dpasted code will only be available for 6 more days):

    BootServiceStart - also here on dpaste
    Code (Text):
    1.  
    2.     package com.example.sprite.half_lifetimer;
    3.  
    4.     import android.content.BroadcastReceiver;
    5.     import android.content.Context;
    6.     import android.content.Intent;
    7.     import android.os.Build;
    8.     import android.util.Log;
    9.  
    10.     public class BootServiceStart extends BroadcastReceiver {
    11.         public void onReceive(Context context, Intent arg1) {
    12.             Intent intent = new Intent(context , NotificationService.class);
    13.  
    14.             if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
    15.                 context.startForegroundService(intent);
    16.             } else {
    17.                 context.startService(intent);
    18.             }
    19.  
    20.             if (GlobalMisc.Debugging) {
    21.                 Log.i("Halflife.BootServiceStart", "Attempted to start NotificationService");
    22.             }
    23.         }
    24.     }
    25.  
    NotificationService - also here on dpaste
    Code (Text):
    1.  
    2.     package com.example.sprite.half_lifetimer;
    3.  
    4.     import android.app.Notification;
    5.     import android.app.NotificationChannel;
    6.     import android.app.NotificationManager;;
    7.     import android.app.Service;
    8.     import android.content.Intent;
    9.     import android.os.Build;
    10.     import android.os.IBinder;
    11.     import android.support.annotation.Nullable;
    12.     import android.support.v4.app.NotificationCompat;
    13.     import android.util.Log;
    14.     import androidx.work.PeriodicWorkRequest;
    15.     import androidx.work.WorkManager;
    16.  
    17.     import java.time.LocalDateTime;
    18.     import java.util.HashMap;
    19.     import java.util.concurrent.TimeUnit;
    20.  
    21.     public class NotificationService extends Service {
    22.         public static HashMap<Integer, Boolean> firedNotifications = new HashMap<>();
    23.         public static LocalDateTime lastNotificationLoopLDT = null;
    24.  
    25.         @Nullable
    26.         public IBinder onBind(Intent intent) {
    27.             return null;
    28.         }
    29.  
    30.         /**
    31.          * Method handles creation of a NotificationChannel and database
    32.          * initialization (for this particular subset of the code), then passing
    33.          * control off to notificationLoop().
    34.          */
    35.         public void onCreate() {
    36.             startForeground(31337, buildForegroundNotification());
    37.  
    38.             if (GlobalMisc.Debugging) {
    39.                 Log.i("Halflife.NotificationService.onCreate", "Started NotificationService");
    40.             }
    41.  
    42.             // Create the NotificationChannel, but only on API 26+ because
    43.             // the NotificationChannel class is new and not in the support library
    44.             if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
    45.                 NotificationChannel chan = new NotificationChannel(
    46.                         "taper-n-clearing-talk", "taper-n-clearing",
    47.                         NotificationManager.IMPORTANCE_NONE);
    48.                 chan.setDescription("Notifications for Taper dosages and Substance clearance");
    49.  
    50.                 // Register the channel with the system; you can't change the importance
    51.                 // or other notification behaviors after this
    52.                 NotificationManager notificationManager = getSystemService(NotificationManager.class);
    53.                 notificationManager.createNotificationChannel(chan);
    54.             }
    55.  
    56.             //get the database ready
    57.             try {
    58.                 Permanence.Misc.init(/*NotificationService.this*/ getApplicationContext());
    59.             } catch (Exception ex) {
    60.                 Log.e("Halflife.notificationLoop", "Unable to init database: " +
    61.                         ex.toString());
    62.             }
    63.  
    64.             if (GlobalMisc.Debugging) {
    65.                 Log.i("Halflife.onCreate", "all valid tapers: " +
    66.                         Permanence.Tapers.loadAllValidTapers(getApplicationContext()).toString());
    67.  
    68.             }
    69.  
    70.             //notificationLoop();
    71.             PeriodicWorkRequest notificationsRequest =
    72.                     new PeriodicWorkRequest.Builder(NotificationWorker.class, 15, TimeUnit.MINUTES)
    73.                             .build();
    74.             WorkManager.getInstance()
    75.                     .enqueue(notificationsRequest);
    76.         }
    77.  
    78.         private Notification buildForegroundNotification() {
    79.             NotificationCompat.Builder b=new NotificationCompat.Builder(this);
    80.  
    81.             b.setOngoing(true)
    82.                     .setContentTitle("HLT Foreground Service")
    83.                     .setContentText("Giving Half-life Timer foreground priority")
    84.                     .setChannelId("taper-n-clearing-talk")
    85.                     .setSmallIcon(getApplicationContext().getResources().getIdentifier(
    86.                             "plus_medical_blue","drawable",
    87.                             getApplicationContext().getPackageName()));
    88.  
    89.             return(b.build());
    90.         }
    91.     }
    92.  
    NotificationWorker - also here on dpaste
    Code (Text):
    1.  
    2.     package com.example.sprite.half_lifetimer;
    3.  
    4.     import android.app.PendingIntent;
    5.     import android.app.TaskStackBuilder;
    6.     import android.content.Context;
    7.     import android.content.Intent;
    8.     import android.support.annotation.NonNull;
    9.     import android.support.v4.app.NotificationCompat;
    10.     import android.support.v4.app.NotificationManagerCompat;
    11.     import android.util.Log;
    12.  
    13.     import androidx.work.Worker;
    14.     import androidx.work.WorkerParameters;
    15.  
    16.     import java.time.Duration;
    17.     import java.time.LocalDateTime;
    18.     import java.time.LocalTime;
    19.  
    20.     public class NotificationWorker extends Worker {
    21.         private boolean notificationDebugging = false;
    22.  
    23.         public NotificationWorker(@NonNull Context context, @NonNull WorkerParameters params) {
    24.             super(context, params);
    25.         }
    26.  
    27.         @Override
    28.         public Result doWork() {
    29.             LocalDateTime nextScheduledDosage;
    30.             long adminDurationMinutes;
    31.  
    32.             if (!notificationDebugging) {
    33.                 if (GlobalMisc.NotificationsEnabled) {
    34.                     //taper notification loop
    35.                     for (Taper taper : Permanence.Tapers.loadAllValidTapers(getApplicationContext())) {
    36.                         //this will handle if any tapers have been added since inception
    37.                         if (!NotificationService.firedNotifications.containsKey(taper.getId())) {
    38.                             NotificationService.firedNotifications.put(taper.getId(), false);
    39.                         }
    40.  
    41.                         //if this is a constrained taper, but we're outside of the window, just
    42.                         //go on to the next taper
    43.                         if (taper.isConstrained() && !taper.inConstraintHours()) {
    44.                             Log.i("Halflife.notificationLoop",
    45.                                     "skipping " + taper.toString() +
    46.                                             " (outside of hourly constraints)");
    47.  
    48.                             continue;
    49.                         }
    50.  
    51.                         if (!NotificationService.firedNotifications.get(taper.getId())) {
    52.                             try {
    53.                                 nextScheduledDosage = taper.findNextScheduledDosageLDT();
    54.                                 if (!taper.isConstrained()) {
    55.                                     Log.i("Halflife.notificationLoop",
    56.                                             "working with unconstrained taper");
    57.  
    58.                                     adminDurationMinutes = Duration.ofDays(1).dividedBy(
    59.                                             taper.getAdminsPerDay()).toMinutes();
    60.                                 } else {
    61.                                     Log.i("Halflife.notificationLoop",
    62.                                             "working with constrained taper");
    63.  
    64.                                     //not sure if this is necessary or not, but might as well
    65.                                     //throw it in since the goddamned code is too complex for me
    66.                                     //to follow right now down below
    67.                                     LocalTime nextDosageTime =
    68.                                             nextScheduledDosage.toLocalTime();
    69.                                     if (nextDosageTime.isBefore(taper.getStartHour()) ||
    70.                                             nextDosageTime.isAfter(taper.getEndHour())) {
    71.                                         Log.i("notificationLoop",
    72.                                                 "skipping " + taper.toString() +
    73.                                                         " (outside of constraint hours)");
    74.  
    75.                                         continue;
    76.                                     }
    77.  
    78.                                     //this part, of course, is necessary
    79.                                     adminDurationMinutes =
    80.                                             Duration.between(taper.getStartHour(),
    81.                                                     taper.getEndHour()).dividedBy(
    82.                                                     taper.getAdminsPerDay())
    83.                                                     .toMinutes();
    84.                                 }
    85.  
    86.                                 if (GlobalMisc.Debugging) {
    87.                                     Log.i("Halflife.notificationLoop", "Checking taper: " +
    88.                                             taper.getName());
    89.                                     Log.i("Halflife.notificationLoop", "nextScheduledDosage " +
    90.                                             "contains: " + nextScheduledDosage.toString());
    91.                                 }
    92.  
    93.                                 if (((NotificationService.lastNotificationLoopLDT != null) &&
    94.                                         nextScheduledDosage.isAfter(
    95.                                                 NotificationService.lastNotificationLoopLDT) &&
    96.                                         nextScheduledDosage.isBefore(
    97.                                                 LocalDateTime.now().plusMinutes(
    98.                                                         (adminDurationMinutes / 5)))) ||
    99.                                         (nextScheduledDosage.isAfter(
    100.                                                 LocalDateTime.now().minusMinutes(1)) &&
    101.                                                 nextScheduledDosage.isBefore(
    102.                                                         LocalDateTime.now().plusMinutes(
    103.                                                                 (adminDurationMinutes / 5))))) {
    104.                                     fireTaperNotification(taper);
    105.  
    106.                                     //set firedNotifications to reflect that we sent this
    107.                                     //notification
    108.                                     NotificationService.firedNotifications.replace(taper.getId(), true);
    109.                                 } else if (GlobalMisc.Debugging) {
    110.                                     Log.i("Halflife.notificationLoop",
    111.                                             "not displaying notification as per " +
    112.                                                     "datetime constraints");
    113.                                 }
    114.                             } catch (Exception ex) {
    115.                                 Log.e("Halflife.notificationLoop",
    116.                                         "Issue finding next scheduled dosage: " +
    117.                                                 ex.toString());
    118.  
    119.                                 return Result.failure();
    120.                             }
    121.                         }
    122.                     }
    123.                 } else {
    124.                     GlobalMisc.debugMsg("NotificationWorker:doWork",
    125.                             "Would have just gone into substance taper notification loop");
    126.                 }
    127.  
    128.                 if (GlobalMisc.NotificationsEnabled) {
    129.                     //substance clearing notification loop
    130.                     //LocalDateTime fiveMinAgo = LocalDateTime.now().minusMinutes(5);
    131.                     for (Substance sub : Permanence.Subs.loadUnarchivedSubstances(
    132.                             getApplicationContext())) {
    133.                         if (GlobalMisc.Debugging) {
    134.                             Log.i("Halflife.notificationLoop",
    135.                                     "Checking sub clearance: " + sub.getCommon_name());
    136.                         }
    137.  
    138.                         //has this substance cleared within the last 5 minutes?
    139.                         LocalDateTime clearedAt = sub.getFullEliminationLDT();
    140.                         if (clearedAt != null) {
    141.                             if (NotificationService.lastNotificationLoopLDT != null) {
    142.                                 if (clearedAt.isAfter(NotificationService.lastNotificationLoopLDT) &&
    143.                                         clearedAt.isBefore(LocalDateTime.now())) {
    144.                                     //fire the notification
    145.                                     try {
    146.                                         fireSubClearedNotification(sub);
    147.                                     } catch (Exception ex) {
    148.                                         Log.i("Halflife.doWork", ex.toString());
    149.  
    150.                                         return Result.failure();
    151.                                     }
    152.                                 }
    153.                             }
    154.                         }
    155.                     }
    156.                 } else {
    157.                     GlobalMisc.debugMsg("NotificationWorker:doWork",
    158.                             "Would have just gone into substance clearing notification loop");
    159.                 }
    160.             } else {
    161.                 Log.i("Halflife.notificationLoop", "In notification debugging " +
    162.                         "mode");
    163.  
    164.                 try {
    165.                     fireTaperNotification(null);
    166.                 } catch (Exception ex) {
    167.                     Log.i("Halflife.doWork", ex.toString());
    168.  
    169.                     return Result.failure();
    170.                 }
    171.             }
    172.  
    173.             NotificationService.lastNotificationLoopLDT = LocalDateTime.now();
    174.  
    175.             return Result.success();
    176.         }
    177.  
    178.         /**
    179.          * Method handles the actual building of the notification regarding
    180.          * the applicable taper, and shows it unless our handy HashMap
    181.          * 'firedNotifications' shows that there is already a notification
    182.          * present for this particular taper.
    183.          *
    184.          * @param taper the taper to display notification for
    185.          */
    186.         private void fireTaperNotification(Taper taper) throws Exception {
    187.             Context ctxt = getApplicationContext();
    188.             float currentDosageScheduled = taper.findCurrentScheduledDosageAmount();
    189.  
    190.             //here's the legitimate meat 'n potatoes for firing a notification
    191.             try {
    192.                 //if we've already blown the dosage required for the next administration, just skip this
    193.                 //one
    194.                 if (currentDosageScheduled <= 0) {
    195.                     Log.d("fireTaperNotification", "More dosage taken than needs to be " +
    196.                             "for the current taper step; skipping this taper administration.");
    197.  
    198.                     return;
    199.                 }
    200.  
    201.                 Intent intent = new Intent(ctxt, AdminData.class);
    202.                 intent.putExtra("SUB_NDX",
    203.                         GlobalMisc.getSubListPositionBySid(taper.getSid()));
    204.                 intent.putExtra("NOTIFICATION_BASED", true);
    205.                 TaskStackBuilder stackBuilder = TaskStackBuilder.create(ctxt);
    206.                 stackBuilder.addParentStack(SubData.class);
    207.                 stackBuilder.addNextIntentWithParentStack(intent);
    208.  
    209.                 Intent delIntent = new Intent(ctxt, NotificationDismissalReceiver.class);
    210.                 delIntent.putExtra("TAPER", true);
    211.                 delIntent.putExtra("SUB_ID", taper.getSid());
    212.  
    213.  
    214.                 PendingIntent pendingIntent =
    215.                         stackBuilder.getPendingIntent(0, PendingIntent.FLAG_UPDATE_CURRENT);
    216.                 PendingIntent pendingDelIntent = PendingIntent.getBroadcast(ctxt, 0,
    217.                         delIntent, PendingIntent.FLAG_UPDATE_CURRENT);
    218.  
    219.                 LocalDateTime latestUsageLDT;
    220.                 LocalDateTime todaysOpeningConstraintLDT;
    221.                 boolean beforeOpeningConstraint = false;
    222.                 latestUsageLDT = Converters.toLocalDateTime(
    223.                         Permanence.Admins.getLatestUsageTimestampBySid(taper.getSid()));
    224.                 if (taper.isConstrained()) {
    225.                     todaysOpeningConstraintLDT =
    226.                             LocalDateTime.now().withHour(taper.getStartHour().getHour())
    227.                                     .withMinute(taper.getStartHour().getMinute())
    228.                                     .withSecond(0);
    229.  
    230.                     if (latestUsageLDT.plus(taper.getTotalConstraintDuration()).isBefore(
    231.                             todaysOpeningConstraintLDT)) {
    232.                         beforeOpeningConstraint = true;
    233.                     }
    234.                 }
    235.  
    236.                 NotificationCompat.Builder builder = new NotificationCompat.Builder(
    237.                         ctxt, "halflife")
    238.                         .setContentTitle("Half-life Timer Taper " + taper.getName())
    239.                         //note that the above line, right after "Due since: " +, will
    240.                         //end up displaying the epoch start date for a taper on a
    241.                         //substance that has no administrations whatsoever
    242.                         .setSmallIcon(ctxt.getResources().getIdentifier("plus_medical_blue",
    243.                                 "drawable", ctxt.getPackageName()))
    244.                         .setPriority(NotificationCompat.PRIORITY_DEFAULT)
    245.                         .setContentIntent(pendingIntent)
    246.                         .setDeleteIntent(pendingDelIntent)
    247.                         .setAutoCancel(true);
    248.  
    249.                 long rawTimestamp = Permanence.Admins.getLatestUsageTimestampBySid(taper.getSid());
    250.  
    251.                 GlobalMisc.debugMsg("fireTaperNotification",
    252.                         "Permanence.Admins.getLatestUsageTimestampBySid returns: " +
    253.                                 rawTimestamp);
    254.  
    255.                 if (Converters.toLocalDateTime(rawTimestamp).isBefore(
    256.                         LocalDateTime.of(1980, 1, 1, 0, 0, 0))) {
    257.                     builder.setContentText("Due: " +
    258.                             String.format("%.2f", currentDosageScheduled) +
    259.                             Permanence.Subs.getUnitsBySID(taper.getSid()) + "/" +
    260.                             Permanence.Subs.loadSubstanceById(
    261.                                     taper.getSid()).getCommon_name() + "\n" +
    262.                             "Due now");
    263.                 } else if (beforeOpeningConstraint) {
    264.                     builder.setContentText("Due:" +
    265.                             currentDosageScheduled +
    266.                             Permanence.Subs.getUnitsBySID(taper.getSid()) + " of " +
    267.                             Permanence.Subs.loadSubstanceById(
    268.                                     taper.getSid()).getCommon_name() + "\n" +
    269.                             "Due since: " +
    270.                             LocalDateTime.now().withHour(taper.getStartHour().getHour())
    271.                                .withMinute(taper.getStartHour().getMinute())
    272.                                .withSecond(0));
    273.                 } else {
    274.                     builder.setContentText("Due:" +
    275.                             currentDosageScheduled +
    276.                             Permanence.Subs.getUnitsBySID(taper.getSid()) + " of " +
    277.                             Permanence.Subs.loadSubstanceById(
    278.                                     taper.getSid()).getCommon_name() + "\n" +
    279.                             "Due since: " +
    280.                             Converters.toLocalDateTime(
    281.                                     Permanence.Admins.getLatestUsageTimestampBySid(
    282.                                             taper.getSid())).plus(
    283.                                     Duration.ofDays(1).dividedBy(
    284.                                             taper.getAdminsPerDay())));
    285.                 }
    286.  
    287.                 NotificationManagerCompat notificationManager =
    288.                         NotificationManagerCompat.from(ctxt);
    289.  
    290.                 notificationManager.notify(1, builder.build());
    291.  
    292.                 if (GlobalMisc.Debugging || notificationDebugging) {
    293.                     Log.i("Halflife.fireNotification",
    294.                             "attempted to send taper notification");
    295.                 }
    296.             } catch (Exception ex) {
    297.                 Log.e("Halflife.fireNotification",
    298.                         "Something broke in taper notification: " + ex.toString());
    299.  
    300.                 throw new Exception("taper notification broke");
    301.             }
    302.         }
    303.  
    304.         private void fireSubClearedNotification(Substance sub) throws Exception {
    305.             Context ctxt = getApplicationContext();
    306.  
    307.             try {
    308.                 Intent intent = new Intent(ctxt,
    309.                         SubsRankedByLastUsage.class);
    310.  
    311.                 PendingIntent pendingIntent = PendingIntent.getActivity(
    312.                         ctxt, 1, intent,
    313.                         PendingIntent.FLAG_UPDATE_CURRENT);
    314.  
    315.                 NotificationCompat.Builder builder = new NotificationCompat.Builder(
    316.                         ctxt, "halflife")
    317.                         .setContentTitle("Half-life Timer Cleared: " + sub.getCommon_name())
    318.                         .setContentText(sub.getCommon_name() + " cleared at " +
    319.                                 sub.getFullEliminationLDT().toString())
    320.                         .setSmallIcon(ctxt.getResources().getIdentifier("plus_medical_blue",
    321.                                 "drawable", ctxt.getPackageName()))
    322.                         .setPriority(NotificationCompat.PRIORITY_DEFAULT)
    323.                         .setContentIntent(pendingIntent)
    324.                         .setAutoCancel(true);
    325.  
    326.                 NotificationManagerCompat notificationManager =
    327.                         NotificationManagerCompat.from(ctxt);
    328.  
    329.                 notificationManager.notify(1, builder.build());
    330.  
    331.                 if (GlobalMisc.Debugging || notificationDebugging) {
    332.                     Log.i("Halflife.fireNotification",
    333.                             "attempted to send sub clearednotification");
    334.                 }
    335.             } catch (Exception ex) {
    336.                 Log.e("Halflife.fireNotification",
    337.                         "Something broke in sub cleared notification: " + ex.toString());
    338.  
    339.                 throw new Exception("sub cleared notification broke");
    340.             }
    341.         }
    342.     }
    343.  
    I would be very grateful to anybody who might be able to offer any insight on why this behavior is happening, tips on how to avoid this behavior, where to find API & other documentation on the older, deprecated JetPack work v1.0.1 library, or what I can do in Android Studio to better diagnose this issue, as attempts for debugging with what I know how to do have proven futile.

    Thank you very much for your time and help on this matter!
     



    1. Download the Forums for Android™ app!


      Download

       
Loading...

Share This Page

Loading...