Merge pull request #18 from jotomo/bolus-delivery-failure-recovery

Bolus delivery failure recovery

Testing-Combo.md

@@ -35,6 +35,16 @@
         It might be interesting to experiment with the Config software to set lower menu or display timeouts
         (or whatever they're called ...) to improve recovery speed.
   - [ ] Same as above while bolusing must report an error and NOT retry the command
+  - [ ] Recovery from connection issues during bolusing
+    - [ ] Bolusing still works => No error dialog, record is added to treatments
+    - [ ] Cancelling the bolus still works (while bolus is in progress)
+    - [ ] Pressing a button on the pump during delivery => Progress dialog freezes, then states that recovery
+          is in process and then closes; no error dialog, record correctly added to treatments
+    - [ ] Breaking the connection e.g. by moving the pump away from phone for up to a minute => same as above
+    - [ ] Same as above but put pump out of reach for 5 minutes => Error dialog, no record in treatments
+    - [ ] Starting a bolus bigger than what's left in the reservoir => Error dialog and a record in treatments with the partially delivered bolus
+    - [ ] When the connection breaks during bolusing, pressing the cancel button should not interfere with recovery and
+          the delivered bolus should be added to treatments
 - [ ] AAPS start
   - [ ] Starting AAPS without a reachable pump must show something sensible in the Combo tab
         (not hanging indefinitely with "initializing" activity)

app/src/main/java/info/nightscout/androidaps/plugins/PumpCombo/ComboPlugin.java

@@ -9,6 +9,8 @@ import org.slf4j.LoggerFactory;
 
 import java.util.Calendar;
 import java.util.Date;
+import java.util.List;
+import java.util.Locale;
 
 import de.jotomo.ruffy.spi.BasalProfile;
 import de.jotomo.ruffy.spi.BolusProgressReporter;
@@ -39,7 +41,6 @@ import info.nightscout.androidaps.interfaces.ConstraintsInterface;
 import info.nightscout.androidaps.interfaces.PluginBase;
 import info.nightscout.androidaps.interfaces.PumpDescription;
 import info.nightscout.androidaps.interfaces.PumpInterface;
-import info.nightscout.androidaps.plugins.ConfigBuilder.ConfigBuilderPlugin;
 import info.nightscout.androidaps.plugins.Overview.events.EventDismissNotification;
 import info.nightscout.androidaps.plugins.Overview.events.EventNewNotification;
 import info.nightscout.androidaps.plugins.Overview.events.EventOverviewBolusProgress;
@@ -47,8 +48,6 @@ import info.nightscout.androidaps.plugins.Overview.notifications.Notification;
 import info.nightscout.androidaps.plugins.PumpCombo.events.EventComboPumpUpdateGUI;
 import info.nightscout.utils.DateUtil;
 
-import static de.jotomo.ruffy.spi.BolusProgressReporter.State.FINISHED;
-
 /**
  * Created by mike on 05.08.2016.
  */
@@ -405,6 +404,8 @@ public class ComboPlugin implements PluginBase, PumpInterface, ConstraintsInterf
             case STOPPED:
                 event.status = MainApp.sResources.getString(R.string.bolusstopped);
                 break;
+            case RECOVERING:
+                event.status = MainApp.sResources.getString(R.string.combo_error_bolus_recovery_progress);
             case FINISHED:
                 // no state, just percent below to close bolus progress dialog
                 break;
@@ -457,6 +458,8 @@ public class ComboPlugin implements PluginBase, PumpInterface, ConstraintsInterf
         }
         lastRequestedBolus = new Bolus(System.currentTimeMillis(), detailedBolusInfo.insulin, true);
 
+        long pumpTimeWhenBolusWasRequested = runCommand(null, 1, ruffyScripter::readPumpState).state.pumpTime;
+
         try {
             pump.activity = MainApp.sResources.getString(R.string.combo_pump_action_bolusing, detailedBolusInfo.insulin);
             MainApp.bus().post(new EventComboPumpUpdateGUI());
@@ -465,26 +468,32 @@ public class ComboPlugin implements PluginBase, PumpInterface, ConstraintsInterf
                 return new PumpEnactResult().success(true).enacted(false);
             }
 
+            BolusProgressReporter progressReporter = detailedBolusInfo.isSMB ? nullBolusProgressReporter : ComboPlugin.bolusProgressReporter;
+
             // start bolus delivery
             bolusInProgress = true;
             CommandResult bolusCmdResult = runCommand(null, 0,
-                    () -> ruffyScripter.deliverBolus(detailedBolusInfo.insulin,
+                    () -> {
-                            detailedBolusInfo.isSMB ? nullBolusProgressReporter : bolusProgressReporter));
+                        return ruffyScripter.deliverBolus(detailedBolusInfo.insulin,
+                                progressReporter);
+                    });
             bolusInProgress = false;
 
-            if (bolusCmdResult.delivered > 0) {
+            if (bolusCmdResult.success) {
-                detailedBolusInfo.insulin = bolusCmdResult.delivered;
+                if (bolusCmdResult.delivered > 0) {
-                detailedBolusInfo.source = Source.USER;
+                    detailedBolusInfo.insulin = bolusCmdResult.delivered;
-                MainApp.getConfigBuilder().addToHistoryTreatment(detailedBolusInfo);
+                    detailedBolusInfo.source = Source.USER;
+                    MainApp.getConfigBuilder().addToHistoryTreatment(detailedBolusInfo);
+                }
+                return new PumpEnactResult()
+                        .success(true)
+                        .enacted(bolusCmdResult.delivered > 0)
+                        .bolusDelivered(bolusCmdResult.delivered)
+                        .carbsDelivered(detailedBolusInfo.carbs);
+            } else {
+                progressReporter.report(BolusProgressReporter.State.RECOVERING, 0, 0);
+                return recoverFromErrorDuringBolusDelivery(detailedBolusInfo, pumpTimeWhenBolusWasRequested);
             }
-
-            return new PumpEnactResult()
-                    .success(bolusCmdResult.success)
-                    .enacted(bolusCmdResult.delivered > 0)
-                    .bolusDelivered(bolusCmdResult.delivered)
-                    .carbsDelivered(detailedBolusInfo.carbs)
-                    .comment(bolusCmdResult.success ? "" :
-                            MainApp.sResources.getString(R.string.combo_bolus_bolus_delivery_failed));
         } finally {
             pump.activity = null;
             MainApp.bus().post(new EventComboPumpUpdateGUI());
@@ -493,6 +502,61 @@ public class ComboPlugin implements PluginBase, PumpInterface, ConstraintsInterf
         }
     }
 
+
+    /**
+     * If there was an error during BolusCommand the scripter reconnects and cleans up. The pump
+     * refuses connections while a bolus delivery is still in progress (once bolus delivery started
+     * it  continues regardless of a connection loss).
+     * Then verify the bolus record we read has a date which is >= the time the bolus was requested
+     * (using the pump's time!). If there is such a bolus with <= the requested amount, then it's
+     * from this command and shall be added to treatments. If the bolus wasn't delivered in full,
+     * add it to treatments but raise a warning. Raise a warning as well if no bolus was delivered
+     * at all.
+     * This all still might fail for very large boluses and earthquakes in which case an error
+     * is raised asking to user to deal with it.
+     */
+    private PumpEnactResult recoverFromErrorDuringBolusDelivery(DetailedBolusInfo detailedBolusInfo, long pumpTimeWhenBolusWasRequested) {
+        log.debug("Trying to determine from pump history what was actually delivered");
+        CommandResult readLastBolusResult = runCommand(null , 2,
+                () -> ruffyScripter.readHistory(new PumpHistoryRequest().bolusHistory(PumpHistoryRequest.LAST)));
+        if (!readLastBolusResult.success || readLastBolusResult.history == null) {
+            // this happens when the cartridge runs empty during delivery, the pump will be in an error
+            // state with multiple alarms ringing and no chance of reading history
+            return new PumpEnactResult().success(false).enacted(false)
+                    .comment(MainApp.sResources.getString(R.string.combo_error_bolus_verification_failed));
+        }
+
+        List<Bolus> bolusHistory = readLastBolusResult.history.bolusHistory;
+        Bolus lastBolus = !bolusHistory.isEmpty() ? bolusHistory.get(0) : null;
+        log.debug("Last bolus read from history: " + lastBolus + ", request time: " +
+                pumpTimeWhenBolusWasRequested + " (" + new Date(pumpTimeWhenBolusWasRequested) + ")");
+
+        if (lastBolus == null // no bolus ever given
+                || lastBolus.timestamp < pumpTimeWhenBolusWasRequested // this is not the bolus you're looking for
+                || !lastBolus.isValid) { // ext/multiwave bolus
+            log.debug("It appears no bolus was delivered");
+            return new PumpEnactResult().success(false).enacted(false)
+                    .comment(MainApp.sResources.getString(R.string.combo_error_no_bolus_delivered));
+        } else if (Math.abs(lastBolus.amount - detailedBolusInfo.insulin) > 0.01) { // bolus only partially delivered
+            detailedBolusInfo.insulin = lastBolus.amount;
+            detailedBolusInfo.source = Source.USER;
+            MainApp.getConfigBuilder().addToHistoryTreatment(detailedBolusInfo);
+            log.debug(String.format(Locale.getDefault(), "Added partial bolus of %.2f to treatments", lastBolus.amount));
+            return new PumpEnactResult().success(false).enacted(true)
+                    .comment(String.format(MainApp.sResources.getString(R.string.combo_error_partial_bolus_delivered),
+                            lastBolus.amount, detailedBolusInfo.insulin));
+        }
+
+        // bolus was correctly and fully delivered
+        detailedBolusInfo.insulin = lastBolus.amount;
+        detailedBolusInfo.source = Source.USER;
+        MainApp.getConfigBuilder().addToHistoryTreatment(detailedBolusInfo);
+        log.debug("Added correctly delivered bolus to treatments");
+        return new PumpEnactResult().success(true).enacted(true)
+                .bolusDelivered(lastBolus.amount)
+                .carbsDelivered(detailedBolusInfo.carbs);
+    }
+
     @Override
     public void stopBolusDelivering() {
         if (bolusInProgress) {

app/src/main/res/layout/overview_bolusprogress_dialog.xml

@@ -11,6 +11,8 @@
         android:id="@+id/overview_bolusprogress_status"
         android:layout_width="wrap_content"
         android:layout_height="wrap_content"
+        android:paddingLeft="10dp"
+        android:paddingRight="10dp"
         android:layout_gravity="center_horizontal" />
 
     <TextView

app/src/main/res/layout/overview_error_dialog.xml

@@ -11,7 +11,8 @@
         android:id="@+id/overview_error_status"
         android:layout_width="wrap_content"
         android:layout_height="wrap_content"
-        android:padding="15dp"
+        android:paddingLeft="10dp"
+        android:paddingRight="10dp"
         android:layout_gravity="center_horizontal" />
 
     <Button

app/src/main/res/values/strings.xml

@@ -812,7 +812,6 @@
     <string name="raise_urgent_alarms_as_android_notification">Use system notifications for alerts</string>
     <string name="combo_pump_never_connected">Never</string>
     <string name="combo_pump_unsupported_operation">Requested operation not supported by pump</string>
-    <string name="combo_bolus_bolus_delivery_failed">Bolus delivery failed. A (partial) bolus might have been delivered. Please check the pump and the treatments tabs and bolus again as needed.</string>
     <string name="combo_force_disabled_notification">Unsafe usage: extended or multiwave boluses have been delivered within the last 6 hours or the selected basal rate is not 1. Loop mode has been set to low-suspend only until 6 hours after the last unsupported bolus or basal rate profile. Only normal boluses are supported in loop mode with basal rate profile 1.</string>
     <string name="bolus_frequency_exceeded">A bolus with the same amount was requested within the last minute. For safety reasons this is disallowed.</string>
     <string name="combo_pump_connected_now">Now</string>
@@ -838,5 +837,10 @@
     <string name="combo_read_full_history_warning">This will read the full history and state of the pump. Everything in \"My Data\" and  the basal rate. Boluses and TBRs will be added to Treatments if they don\'t already exist. This can cause entries to be duplicated because the pump\'s time is imprecise. Using this when normally looping with the pump is highly discouraged and reserved for special circumstances. If you still want to do this, long press this button again.\n\nWARNING: this can trigger a bug which causes the pump to reject all connection attempts and requires pressing a button on the pump to recover and should therefore be avoided.</string>
     <string name="combo_read_full_history_confirmation">Are you really sure you want to read all pump data and take the consequences of this action?</string>
     <string name="combo_pump_tbr_cancelled_warrning">TBR CANCELLED warning was confirmed</string>
+    <string name="combo_error_no_bolus_delivered">Bolus delivery failed. It appears no bolus was delivered. To be sure, please check the pump to avoid a double bolus and then bolus again. To guard against bugs, boluses are not automatically retried.</string>
+    <string name="combo_error_partial_bolus_delivered">Only %.2f U of the requested bolus of %.2f U was delivered due to an error. Please check the pump to verify this and take appropriate actions.</string>
+    <string name="combo_activity_verifying_delivered_bolus">Verifying delivered bolus</string>
+    <string name="combo_error_bolus_verification_failed">Delivering the bolus and verifying the pump\'s history failed, please check the pump and manually create a bolus record using the Careportal tab if a bolus was delivered.</string>
+    <string name="combo_error_bolus_recovery_progress">Recovering from connection loss</string>
 </resources>
 

ruffy-spi/src/main/java/de/jotomo/ruffy/spi/BolusProgressReporter.java

@@ -7,6 +7,7 @@ public interface BolusProgressReporter {
         DELIVERED,
         STOPPING,
         STOPPED,
+        RECOVERING,
         FINISHED
     }
 

ruffy-spi/src/main/java/de/jotomo/ruffy/spi/PumpState.java

@@ -81,15 +81,19 @@ public class PumpState {
     @Override
     public String toString() {
         return "PumpState{" +
-                "menu=" + menu +
+                "timestamp=" + timestamp +
+                ", pumpTime=" + pumpTime +
+                ", menu='" + menu + '\'' +
+                ", suspended=" + suspended +
                 ", tbrActive=" + tbrActive +
                 ", tbrPercent=" + tbrPercent +
                 ", tbrRate=" + tbrRate +
                 ", tbrRemainingDuration=" + tbrRemainingDuration +
-                ", suspended=" + suspended +
+                ", activeAlert=" + activeAlert +
                 ", batteryState=" + batteryState +
                 ", insulinState=" + insulinState +
                 ", activeBasalProfileNumber=" + activeBasalProfileNumber +
+                ", unsafeUsageDetected=" + unsafeUsageDetected +
                 '}';
     }
 }

ruffy-spi/src/main/java/de/jotomo/ruffy/spi/history/Bolus.java

@@ -39,7 +39,7 @@ public class Bolus extends HistoryRecord {
     @Override
     public String toString() {
         return "Bolus{" +
-                "timestamp=" + timestamp + "(" + new Date(timestamp) + ")" +
+                "timestamp=" + timestamp + " (" + new Date(timestamp) + ")" +
                 ", amount=" + amount +
                 '}';
     }

ruffyscripter/src/main/java/de/jotomo/ruffyscripter/RuffyScripter.java

@@ -196,6 +196,7 @@ public class RuffyScripter implements RuffyCommands {
             return;
         }
         try {
+            log.debug("Disconnecting, requested by ...", new Exception());
             ruffyService.doRTDisconnect();
         } catch (RemoteException e) {
             // ignore
@@ -363,21 +364,6 @@ public class RuffyScripter implements RuffyCommands {
                 return false;
             }
         }
-
-        // if everything broke before, the pump might still be delivering a bolus, if that's the case, wait for bolus to finish
-        Double bolusRemaining = (Double) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_REMAINING);
-        BolusType bolusType = (BolusType) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_TYPE);
-        if (bolusType != null && bolusType == BolusType.NORMAL) {
-            try {
-                while (isConnected() && bolusRemaining != null) {
-                    log.debug("Waiting for bolus from previous connection to complete, remaining: " + bolusRemaining);
-                    waitForScreenUpdate();
-                }
-            } catch (Exception e) {
-                log.error("Exception waiting for bolus from previous command to finish", e);
-                return false;
-            }
-        }
         return true;
     }
 
@@ -404,19 +390,17 @@ public class RuffyScripter implements RuffyCommands {
             }
         }
 
-        // A BOLUS CANCELLED alert is raised BEFORE a bolus is started. If a disconnect occurs after a
-        // bolus has started (or the user interacts with the pump) the bolus continues.
-        // If that happened, wait till the pump has finished the bolus, then it can be read from
-        // the history as delivered.
-        Double bolusRemaining = (Double) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_REMAINING);
-        BolusType bolusType = (BolusType) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_TYPE);
-        while (isConnected() && bolusRemaining != null && bolusType == BolusType.NORMAL) {
-            waitForScreenUpdate();
-            bolusRemaining = (Double) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_REMAINING);
-            bolusType = (BolusType) getCurrentMenu().getAttribute(MenuAttribute.BOLUS_TYPE);
-        }
         boolean connected = isConnected();
         if (connected) {
+            long menuTime = this.menuLastUpdated;
+            waitForScreenUpdate();
+            if (menuTime == this.menuLastUpdated) {
+                log.error("NOT RECEIVING UPDATES YET JOE");
+            }
+            while(currentMenu==null) {
+                log.warn("waiting for currentMenu to become != null");
+                waitForScreenUpdate();
+            }
             MenuType menuType = getCurrentMenu().getType();
             if (menuType != MenuType.MAIN_MENU && menuType != MenuType.WARNING_OR_ERROR) {
                 returnToRootMenu();
@@ -495,6 +479,7 @@ public class RuffyScripter implements RuffyCommands {
             return state;
         }
 
+        log.debug("Parsing menu: " + menu);
         MenuType menuType = menu.getType();
         state.menu = menuType.name();
 
@@ -505,7 +490,7 @@ public class RuffyScripter implements RuffyCommands {
 
             if (bolusType != null && bolusType != BolusType.NORMAL || !activeBasalRate.equals(1)) {
                 state.unsafeUsageDetected = true;
-            } else if (tbrPercentage != 100) {
+            } else if (tbrPercentage != null && tbrPercentage != 100) {
                 state.tbrActive = true;
                 Double displayedTbr = (Double) menu.getAttribute(MenuAttribute.TBR);
                 state.tbrPercent = displayedTbr.intValue();
@@ -513,26 +498,41 @@ public class RuffyScripter implements RuffyCommands {
                 state.tbrRemainingDuration = durationMenuTime.getHour() * 60 + durationMenuTime.getMinute();
                 state.tbrRate = ((double) menu.getAttribute(MenuAttribute.BASAL_RATE));
             }
-            state.batteryState = ((int) menu.getAttribute(MenuAttribute.BATTERY_STATE));
+            if (menu.attributes().contains(MenuAttribute.BATTERY_STATE)) {
-            state.insulinState = ((int) menu.getAttribute(MenuAttribute.INSULIN_STATE));
+                state.batteryState = ((int) menu.getAttribute(MenuAttribute.BATTERY_STATE));
-            MenuTime time = (MenuTime) menu.getAttribute(MenuAttribute.TIME);
+            }
-            Date date = new Date();
+            if (menu.attributes().contains(MenuAttribute.INSULIN_STATE)) {
-            date.setHours(time.getHour());
+                state.insulinState = ((int) menu.getAttribute(MenuAttribute.INSULIN_STATE));
-            date.setMinutes(time.getMinute());
+            }
-            state.pumpTime = date.getTime();
+            if (menu.attributes().contains(MenuAttribute.TIME)) {
+                MenuTime time = (MenuTime) menu.getAttribute(MenuAttribute.TIME);
+                Date date = new Date();
+                date.setHours(time.getHour());
+                date.setMinutes(time.getMinute());
+                date.setSeconds(0);
+                state.pumpTime = date.getTime() - date.getTime() % 1000;
+            }
         } else if (menuType == MenuType.WARNING_OR_ERROR) {
             state.activeAlert = readWarningOrErrorCode();
         } else if (menuType == MenuType.STOP) {
             state.suspended = true;
-            state.batteryState = ((int) menu.getAttribute(MenuAttribute.BATTERY_STATE));
+            if (menu.attributes().contains(MenuAttribute.BATTERY_STATE)) {
-            state.insulinState = ((int) menu.getAttribute(MenuAttribute.INSULIN_STATE));
+                state.batteryState = ((int) menu.getAttribute(MenuAttribute.BATTERY_STATE));
-            MenuTime time = (MenuTime) menu.getAttribute(MenuAttribute.TIME);
+            }
-            Date date = new Date();
+            if (menu.attributes().contains(MenuAttribute.INSULIN_STATE)) {
-            date.setHours(time.getHour());
+                state.insulinState = ((int) menu.getAttribute(MenuAttribute.INSULIN_STATE));
-            date.setMinutes(time.getMinute());
+            }
-            state.pumpTime = date.getTime();
+            if (menu.attributes().contains(MenuAttribute.TIME)) {
+                MenuTime time = (MenuTime) menu.getAttribute(MenuAttribute.TIME);
+                Date date = new Date();
+                date.setHours(time.getHour());
+                date.setMinutes(time.getMinute());
+                date.setSeconds(0);
+                state.pumpTime = date.getTime() - date.getTime() % 1000;
+            }
         }
 
+        log.debug("State read: " + state);
         return state;
     }