From 3ecbd3e1bdd95666e3540a41b5b71e5769ab5fc9 Mon Sep 17 00:00:00 2001 From: Bart Sopers Date: Mon, 9 Dec 2019 21:45:08 +0100 Subject: [PATCH] Add logging in OmnipodManager --- .../pump/omnipod/comm/OmnipodManager.java | 142 ++++++++++++++---- .../omnipod/defs/schedule/BasalSchedule.java | 4 +- 2 files changed, 119 insertions(+), 27 deletions(-) diff --git a/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/comm/OmnipodManager.java b/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/comm/OmnipodManager.java index 442a12e176..d92371c032 100644 --- a/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/comm/OmnipodManager.java +++ b/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/comm/OmnipodManager.java @@ -83,16 +83,21 @@ public class OmnipodManager { } public synchronized Single pairAndPrime() { - if (podState == null) { - podState = communicationService.executeAction( - new PairAction(new PairService(), podStateChangedHandler)); - } - if (!podState.getSetupProgress().isBefore(SetupProgress.PRIMING_FINISHED)) { - throw new IllegalSetupProgressException(SetupProgress.ADDRESS_ASSIGNED, podState.getSetupProgress()); - } + logStartingCommandExecution("pairAndPrime"); - communicationService.executeAction(new PrimeAction(new PrimeService(), podState)); + try { + if (podState == null) { + podState = communicationService.executeAction( + new PairAction(new PairService(), podStateChangedHandler)); + } + if (!podState.getSetupProgress().isBefore(SetupProgress.PRIMING_FINISHED)) { + throw new IllegalSetupProgressException(SetupProgress.ADDRESS_ASSIGNED, podState.getSetupProgress()); + } + communicationService.executeAction(new PrimeAction(new PrimeService(), podState)); + } finally { + logCommandExecutionFinished("pairAndPrime"); + } long delayInSeconds = calculateBolusDuration(OmnipodConst.POD_PRIME_BOLUS_UNITS, OmnipodConst.POD_PRIMING_DELIVERY_RATE).getStandardSeconds(); return Single.timer(delayInSeconds, TimeUnit.SECONDS) // @@ -108,9 +113,16 @@ public class OmnipodManager { throw new IllegalSetupProgressException(SetupProgress.CANNULA_INSERTING, podState.getSetupProgress()); } - communicationService.executeAction(new InsertCannulaAction(new InsertCannulaService(), podState, basalSchedule)); + logStartingCommandExecution("insertCannula [basalSchedule=" + basalSchedule + "]"); + + try { + communicationService.executeAction(new InsertCannulaAction(new InsertCannulaService(), podState, basalSchedule)); + } finally { + logCommandExecutionFinished("insertCannula"); + } long delayInSeconds = calculateBolusDuration(OmnipodConst.POD_CANNULA_INSERTION_BOLUS_UNITS, OmnipodConst.POD_CANNULA_INSERTION_DELIVERY_RATE).getStandardSeconds(); + return Single.timer(delayInSeconds, TimeUnit.SECONDS) // .map(o -> verifySetupAction(statusResponse -> InsertCannulaAction.updateCannulaInsertionStatus(podState, statusResponse), SetupProgress.COMPLETED)) // @@ -122,40 +134,76 @@ public class OmnipodManager { throw new IllegalSetupProgressException(SetupProgress.PRIMING_FINISHED, null); } - return communicationService.executeAction(new GetStatusAction(podState)); + logStartingCommandExecution("getPodStatus"); + + try { + return communicationService.executeAction(new GetStatusAction(podState)); + } finally { + logCommandExecutionFinished("getPodStatus"); + } } public synchronized PodInfoResponse getPodInfo(PodInfoType podInfoType) { assertReadyForDelivery(); - return communicationService.executeAction(new GetPodInfoAction(podState, podInfoType)); + logStartingCommandExecution("getPodInfo"); + + try { + return communicationService.executeAction(new GetPodInfoAction(podState, podInfoType)); + } finally { + logCommandExecutionFinished("getPodInfo"); + } } public synchronized void acknowledgeAlerts() { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new AcknowledgeAlertsAction(podState, podState.getActiveAlerts()))); + logStartingCommandExecution("acknowledgeAlerts"); + + try { + executeAndVerify(() -> communicationService.executeAction(new AcknowledgeAlertsAction(podState, podState.getActiveAlerts()))); + } finally { + logCommandExecutionFinished("acknowledgeAlerts"); + } } public synchronized void setBasalSchedule(BasalSchedule schedule, boolean acknowledgementBeep) { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new SetBasalScheduleAction(podState, schedule, - false, podState.getScheduleOffset(), acknowledgementBeep))); + logStartingCommandExecution("setBasalSchedule [basalSchedule=" + schedule + ", acknowledgementBeep=" + acknowledgementBeep + "]"); + + try { + executeAndVerify(() -> communicationService.executeAction(new SetBasalScheduleAction(podState, schedule, + false, podState.getScheduleOffset(), acknowledgementBeep))); + } finally { + logCommandExecutionFinished("setBasalSchedule"); + } } public synchronized void setTemporaryBasal(TempBasalPair tempBasalPair, boolean acknowledgementBeep, boolean completionBeep) { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new SetTempBasalAction(new SetTempBasalService(), - podState, tempBasalPair.getInsulinRate(), Duration.standardMinutes(tempBasalPair.getDurationMinutes()), - acknowledgementBeep, completionBeep))); + logStartingCommandExecution("setTemporaryBasal [tempBasalPair=" + tempBasalPair + ", acknowledgementBeep=" + acknowledgementBeep + ", completionBeep=" + completionBeep + "]"); + + try { + executeAndVerify(() -> communicationService.executeAction(new SetTempBasalAction(new SetTempBasalService(), + podState, tempBasalPair.getInsulinRate(), Duration.standardMinutes(tempBasalPair.getDurationMinutes()), + acknowledgementBeep, completionBeep))); + } finally { + logCommandExecutionFinished("setTemporaryBasal"); + } } public synchronized void cancelTemporaryBasal(boolean acknowledgementBeep) { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new CancelDeliveryAction(podState, DeliveryType.TEMP_BASAL, acknowledgementBeep))); + logStartingCommandExecution("cancelTemporaryBasal [acknowledgementBeep=" + acknowledgementBeep + "]"); + + try { + executeAndVerify(() -> communicationService.executeAction(new CancelDeliveryAction(podState, DeliveryType.TEMP_BASAL, acknowledgementBeep))); + } finally { + logCommandExecutionFinished("cancelTemporaryBasal"); + } } // Returns a SingleSubject that returns when the bolus has finished. @@ -164,6 +212,8 @@ public class OmnipodManager { public synchronized BolusCommandResult bolus(Double units, boolean acknowledgementBeep, boolean completionBeep, BolusProgressIndicationConsumer progressIndicationConsumer) { assertReadyForDelivery(); + logStartingCommandExecution("bolus [units=" + units + ", acknowledgementBeep=" + acknowledgementBeep + ", completionBeep=" + completionBeep + "]"); + CommandDeliveryStatus commandDeliveryStatus = CommandDeliveryStatus.SUCCESS; try { @@ -178,6 +228,8 @@ public class OmnipodManager { LOG.error("Caught exception[certainFailure=false] in bolus", ex); } commandDeliveryStatus = CommandDeliveryStatus.UNCERTAIN_FAILURE; + } finally { + logCommandExecutionFinished("bolus"); } DateTime startDate = DateTime.now().minus(OmnipodConst.AVERAGE_BOLUS_COMMAND_COMMUNICATION_DURATION); @@ -245,12 +297,16 @@ public class OmnipodManager { throw new IllegalDeliveryStatusException(DeliveryStatus.BOLUS_IN_PROGRESS, podState.getLastDeliveryStatus()); } + logStartingCommandExecution("cancelBolus [acknowledgementBeep=" + acknowledgementBeep + "]"); + try { executeAndVerify(() -> communicationService.executeAction(new CancelDeliveryAction(podState, DeliveryType.BOLUS, acknowledgementBeep))); } catch (PodFaultException ex) { if (isLoggingEnabled()) { LOG.info("Ignoring PodFaultException in cancelBolus", ex); } + } finally { + logCommandExecutionFinished("cancelBolus"); } activeBolusData.getDisposables().dispose(); @@ -263,14 +319,26 @@ public class OmnipodManager { public synchronized void suspendDelivery(boolean acknowledgementBeep) { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new CancelDeliveryAction(podState, EnumSet.allOf(DeliveryType.class), acknowledgementBeep))); + logStartingCommandExecution("suspendDelivery [acknowledgementBeep=" + acknowledgementBeep + "]"); + + try { + executeAndVerify(() -> communicationService.executeAction(new CancelDeliveryAction(podState, EnumSet.allOf(DeliveryType.class), acknowledgementBeep))); + } finally { + logCommandExecutionFinished("suspendDelivery"); + } } public synchronized void resumeDelivery(boolean acknowledgementBeep) { assertReadyForDelivery(); - executeAndVerify(() -> communicationService.executeAction(new SetBasalScheduleAction(podState, podState.getBasalSchedule(), - true, podState.getScheduleOffset(), acknowledgementBeep))); + logStartingCommandExecution("resumeDelivery [acknowledgementBeep=" + acknowledgementBeep + "]"); + + try { + executeAndVerify(() -> communicationService.executeAction(new SetBasalScheduleAction(podState, podState.getBasalSchedule(), + true, podState.getScheduleOffset(), acknowledgementBeep))); + } finally { + logCommandExecutionFinished("resumeDelivery"); + } } // CAUTION: cancels TBR and bolus @@ -279,13 +347,19 @@ public class OmnipodManager { public synchronized void setTime(boolean acknowledgementBeeps) { assertReadyForDelivery(); - suspendDelivery(acknowledgementBeeps); + logStartingCommandExecution("setTime [acknowledgementBeeps=" + acknowledgementBeeps + "]"); - // Joda seems to cache the default time zone, so we use the JVM's - DateTimeZone.setDefault(DateTimeZone.forTimeZone(TimeZone.getDefault())); - podState.setTimeZone(DateTimeZone.getDefault()); + try { + suspendDelivery(acknowledgementBeeps); - resumeDelivery(acknowledgementBeeps); + // Joda seems to cache the default time zone, so we use the JVM's + DateTimeZone.setDefault(DateTimeZone.forTimeZone(TimeZone.getDefault())); + podState.setTimeZone(DateTimeZone.getDefault()); + + resumeDelivery(acknowledgementBeeps); + } finally { + logCommandExecutionFinished("setTime"); + } } public synchronized void deactivatePod() { @@ -293,6 +367,8 @@ public class OmnipodManager { throw new IllegalSetupProgressException(SetupProgress.ADDRESS_ASSIGNED, null); } + logStartingCommandExecution("deactivatePod"); + try { // Never send acknowledgement beeps here. Matches the PDM's behavior executeAndVerify(() -> communicationService.executeAction(new DeactivatePodAction(podState, false))); @@ -300,6 +376,8 @@ public class OmnipodManager { if (isLoggingEnabled()) { LOG.info("Ignoring PodFaultException in deactivatePod", ex); } + } finally { + logCommandExecutionFinished("deactivatePod"); } resetPodState(); @@ -416,6 +494,18 @@ public class OmnipodManager { return CommandDeliveryStatus.SUCCESS; } + private void logStartingCommandExecution(String action) { + if (isLoggingEnabled()) { + LOG.debug("Starting command execution for action: " + action); + } + } + + private void logCommandExecutionFinished(String action) { + if (isLoggingEnabled()) { + LOG.debug("Command execution finished for action: " + action); + } + } + private boolean isLoggingEnabled() { return L.isEnabled(L.PUMP); } diff --git a/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/defs/schedule/BasalSchedule.java b/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/defs/schedule/BasalSchedule.java index 416eeeb420..61e487e7bd 100644 --- a/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/defs/schedule/BasalSchedule.java +++ b/app/src/main/java/info/nightscout/androidaps/plugins/pump/omnipod/defs/schedule/BasalSchedule.java @@ -84,7 +84,9 @@ public class BasalSchedule { @Override public String toString() { - return "BasalSchedule (" + entries.size() + " entries)"; + return "BasalSchedule{" + + "entries=" + entries + + '}'; } public static class BasalScheduleDurationEntry {