From 0516eacfe55d4861fe2d0b5bd3045a0d8427579d Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 14:34:44 +0200 Subject: [PATCH 1/7] ConfigBuilder.applyAPSResult: log request rate. --- .../plugins/ConfigBuilder/ConfigBuilderPlugin.java | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/app/src/main/java/info/nightscout/androidaps/plugins/ConfigBuilder/ConfigBuilderPlugin.java b/app/src/main/java/info/nightscout/androidaps/plugins/ConfigBuilder/ConfigBuilderPlugin.java index 0629011397..31907f16dc 100644 --- a/app/src/main/java/info/nightscout/androidaps/plugins/ConfigBuilder/ConfigBuilderPlugin.java +++ b/app/src/main/java/info/nightscout/androidaps/plugins/ConfigBuilder/ConfigBuilderPlugin.java @@ -578,9 +578,10 @@ public class ConfigBuilderPlugin implements PluginBase, PumpInterface, Constrain result.comment = "Temp basal set correctly"; result.success = true; if (Config.logCongigBuilderActions) - log.debug("applyAPSRequest: Temp basal set correctly " + - "(no pump request needed, pump is still running request TBR for " - + getTempBasalRemainingMinutesFromHistory() + " more minutes)"); + log.debug("applyAPSRequest: Temp basal set correctly " + + "(no pump request needed, pump is still running requested rate of " + + request.rate + " for " + + (int) getTempBasalRemainingMinutesFromHistory() + " more minutes)"); } else { if (Config.logCongigBuilderActions) log.debug("applyAPSRequest: setTempBasalAbsolute()"); From d79b22194080d5a4fc80e7ada4c3b03337074107 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 14:35:24 +0200 Subject: [PATCH 2/7] CommandException: provide message for printing. --- .../de/jotomo/ruffyscripter/commands/CommandException.java | 5 +++++ .../java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java | 2 +- 2 files changed, 6 insertions(+), 1 deletion(-) diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/CommandException.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/CommandException.java index 4e6637f84f..5c25ba914c 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/CommandException.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/CommandException.java @@ -23,6 +23,11 @@ public class CommandException extends RuntimeException { return this; } + @Override + public String getMessage() { + return message; + } + public CommandException message(String message) { this.message = message; return this; diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java index ec29a6091a..f27b378564 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java @@ -172,7 +172,7 @@ public class SetTbrCommand implements Command { private void verifyDisplayedTbrPercentage(RuffyScripter scripter) { scripter.verifyMenuIsDisplayed(MenuType.TBR_SET); long displayedPercentage = readDisplayedTbrPercentage(scripter); - if (displayedPercentage != this.percentage) { + if (displayedPercentage != percentage) { log.debug("Final displayed TBR percentage: " + displayedPercentage); throw new CommandException().message("Failed to set TBR percentage"); } From f6b1887fd2692833153f2affd4be23e9162aab41 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Mon, 24 Jul 2017 15:17:06 +0200 Subject: [PATCH 3/7] Logging: Print filename and line instead of logger name. --- app/src/main/assets/logback.xml | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/app/src/main/assets/logback.xml b/app/src/main/assets/logback.xml index 41ed7bdefe..82ab67b00a 100644 --- a/app/src/main/assets/logback.xml +++ b/app/src/main/assets/logback.xml @@ -15,7 +15,7 @@ 120 - %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n + %d{HH:mm:ss.SSS} [%thread] %-5level [%file:%line]: %msg%n @@ -24,7 +24,7 @@ %logger{0} - [%thread] %-5level %logger{36} - %msg%n + [%thread] %-5level [%file:%line]: %msg%n From e1b63a4a74cf11f1de0c3f792529ff298555d050 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 15:50:07 +0200 Subject: [PATCH 4/7] Command doc. --- .../java/de/jotomo/ruffyscripter/commands/Command.java | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/Command.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/Command.java index c18ce48c07..33d10fc223 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/Command.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/Command.java @@ -5,6 +5,13 @@ import java.util.List; import de.jotomo.ruffyscripter.PumpState; import de.jotomo.ruffyscripter.RuffyScripter; +/** + * Interface for all commands to be executed by the pump. + * + * Note on cammond methods and timing: a method shall wait before and after executing + * as necessary to not cause timing issues, so the caller can just call methods in + * sequence, letting the methods take care of waits. + */ public interface Command { CommandResult execute(RuffyScripter ruffyScripter, PumpState initialPumpState); List validateArguments(); From da69e69570caf66dec164feb387c84812445e979 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 14:46:00 +0200 Subject: [PATCH 5/7] BolusCommand: remove retry logic, add extra checks for final bolus. --- .../ruffyscripter/commands/BolusCommand.java | 32 ++++++++----------- 1 file changed, 13 insertions(+), 19 deletions(-) diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java index acf88c36c0..c0819c591e 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java @@ -39,25 +39,8 @@ public class BolusCommand implements Command { try { enterBolusMenu(scripter); - boolean bolusAmountInputSuccess = false; - int bolusAmountInputRetries = 2; - // see SetTbrCommand.execute for an explanation why we're looping here - while (!bolusAmountInputSuccess) { - try { - inputBolusAmount(scripter); - // TODO v2 this call can probably be removed by now - SystemClock.sleep(750); - verifyDisplayedBolusAmount(scripter); - bolusAmountInputSuccess = true; - } catch (CommandException e) { - if (bolusAmountInputRetries >= 0) { - log.warn("Failed to set bolus amount, retrying", e); - bolusAmountInputRetries--; - } else { - throw e; - } - } - } + inputBolusAmount(scripter); + verifyDisplayedBolusAmount(scripter); // confirm bolus scripter.verifyMenuIsDisplayed(MenuType.BOLUS_ENTER); @@ -112,6 +95,9 @@ public class BolusCommand implements Command { scripter.pressUpKey(); SystemClock.sleep(100); } + // Give the pump time to finish any scrolling that might still be going on, can take + // up to 1100s. Plus some extra time to be sure + SystemClock.sleep(2000); } private void verifyDisplayedBolusAmount(RuffyScripter scripter) { @@ -121,6 +107,14 @@ public class BolusCommand implements Command { if (Math.abs(displayedBolus - bolus) > 0.05) { throw new CommandException().message("Failed to set correct bolus. Expected: " + bolus + ", actual: " + displayedBolus); } + + // check again to ensure the displayed value hasn't change due to due scrolling taking extremely long + SystemClock.sleep(2000); + double refreshedDisplayedBolus = readDisplayedBolusAmount(scripter); + if (Math.abs(displayedBolus - refreshedDisplayedBolus) > 0.05) { + throw new CommandException().message("Failed to set bolus: bolus changed after input stopped from " + + displayedBolus + " -> " + refreshedDisplayedBolus); + } } private double readDisplayedBolusAmount(RuffyScripter scripter) { From 02c80a924cf3903196fb7ce62bc7e5425fe7d2d5 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 16:07:22 +0200 Subject: [PATCH 6/7] SetTbrCommand: remove retry logic, add extra checks for final bolus. --- .../ruffyscripter/commands/SetTbrCommand.java | 75 +++++++------------ 1 file changed, 28 insertions(+), 47 deletions(-) diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java index f27b378564..b0a47e00d0 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java @@ -57,34 +57,8 @@ public class SetTbrCommand implements Command { public CommandResult execute(RuffyScripter scripter, PumpState initialPumpState) { try { enterTbrMenu(scripter); - - boolean tbrPercentInputSuccess = false; - int tbrPercentInputRetries = 2; - // Setting TBR percentage/duration works most of the time. Occassionnally though, - // button presses don't take, e.g. we press down 10 times to go from 100% to 0% - // but the pump ends on 30%. In that case restarting inputing the TBR, so we start - // again and push down 3 times. - // Either our timings are of, or the pump sometimes is sluggish. I suspect the later, - // based on an error when switching from TBR_SET to TBR_DURATION took more than 1.1s - // and 4 menu updates were sent before the menu was finally switched. This happened - // around the time when a running TBR was about to run out. So maybe the pump was busy - // updating its history records. - while (!tbrPercentInputSuccess) { - try { - inputTbrPercentage(scripter); - // TODO v2 this can probably be removed by now - SystemClock.sleep(750); - verifyDisplayedTbrPercentage(scripter); - tbrPercentInputSuccess = true; - } catch (CommandException e) { - if (tbrPercentInputRetries >= 0) { - log.warn("Setting TBR percentage failed, retrying", e); - tbrPercentInputRetries--; - } else { - throw e; - } - } - } + inputTbrPercentage(scripter); + verifyDisplayedTbrPercentage(scripter); if (percentage == 100) { cancelTbrAndConfirmCancellationWarning(scripter); @@ -95,25 +69,8 @@ public class SetTbrCommand implements Command { scripter.waitForMenuUpdate(); scripter.verifyMenuIsDisplayed(MenuType.TBR_DURATION); - boolean tbrDurationSuccess = false; - int tbrDurationRetries = 2; - // see above why we loop here - while (!tbrDurationSuccess) { - try { - inputTbrDuration(scripter); - // TODO v2 this can probably be removed by now - SystemClock.sleep(750); - verifyDisplayedTbrDuration(scripter); - tbrDurationSuccess = true; - } catch (CommandException e) { - if (tbrDurationRetries >= 0) { - log.warn("Setting TBR duration failed, retrying", e); - tbrDurationRetries--; - } else { - throw e; - } - } - } + inputTbrDuration(scripter); + verifyDisplayedTbrDuration(scripter); // confirm TBR scripter.pressCheckKey(); @@ -167,6 +124,9 @@ public class SetTbrCommand implements Command { SystemClock.sleep(100); log.debug("Push #" + (i + 1)); } + // Give the pump time to finish any scrolling that might still be going on, can take + // up to 1100s. Plus some extra time to be sure + SystemClock.sleep(2000); } private void verifyDisplayedTbrPercentage(RuffyScripter scripter) { @@ -176,6 +136,15 @@ public class SetTbrCommand implements Command { log.debug("Final displayed TBR percentage: " + displayedPercentage); throw new CommandException().message("Failed to set TBR percentage"); } + + // check again to ensure the displayed value hasn't change due to due scrolling taking extremely long + SystemClock.sleep(2000); + long refreshedDisplayedTbrPecentage = readDisplayedTbrPercentage(scripter); + if (displayedPercentage != refreshedDisplayedTbrPecentage) { + throw new CommandException().message("Failed to set TBR percentage: " + + "percentage changed after input stopped from " + + displayedPercentage + " -> " + refreshedDisplayedTbrPecentage); + } } private long readDisplayedTbrPercentage(RuffyScripter scripter) { @@ -220,6 +189,9 @@ public class SetTbrCommand implements Command { SystemClock.sleep(100); log.debug("Push #" + (i + 1)); } + // Give the pump time to finish any scrolling that might still be going on, can take + // up to 1100s. Plus some extra time to be sure + SystemClock.sleep(2000); } private void verifyDisplayedTbrDuration(RuffyScripter scripter) { @@ -229,6 +201,15 @@ public class SetTbrCommand implements Command { log.debug("Final displayed TBR duration: " + displayedDuration); throw new CommandException().message("Failed to set TBR duration"); } + + // check again to ensure the displayed value hasn't change due to due scrolling taking extremely long + SystemClock.sleep(2000); + long refreshedDisplayedTbrDuration = readDisplayedTbrDuration(scripter); + if (displayedDuration != refreshedDisplayedTbrDuration) { + throw new CommandException().message("Failed to set TBR duration: " + + "duration changed after input stopped from " + + displayedDuration + " -> " + refreshedDisplayedTbrDuration); + } } private long readDisplayedTbrDuration(RuffyScripter scripter) { From 78d2322c140e6c3723e13453a55bf5b6c366a0f4 Mon Sep 17 00:00:00 2001 From: Johannes Mockenhaupt Date: Wed, 26 Jul 2017 18:02:21 +0200 Subject: [PATCH 7/7] Typos. --- .../java/de/jotomo/ruffyscripter/commands/BolusCommand.java | 2 +- .../java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java index c0819c591e..ae3aed3899 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/BolusCommand.java @@ -96,7 +96,7 @@ public class BolusCommand implements Command { SystemClock.sleep(100); } // Give the pump time to finish any scrolling that might still be going on, can take - // up to 1100s. Plus some extra time to be sure + // up to 1100ms. Plus some extra time to be sure SystemClock.sleep(2000); } diff --git a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java index b0a47e00d0..abfbf5bcbe 100644 --- a/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java +++ b/app/src/main/java/de/jotomo/ruffyscripter/commands/SetTbrCommand.java @@ -125,7 +125,7 @@ public class SetTbrCommand implements Command { log.debug("Push #" + (i + 1)); } // Give the pump time to finish any scrolling that might still be going on, can take - // up to 1100s. Plus some extra time to be sure + // up to 1100ms. Plus some extra time to be sure SystemClock.sleep(2000); } @@ -190,7 +190,7 @@ public class SetTbrCommand implements Command { log.debug("Push #" + (i + 1)); } // Give the pump time to finish any scrolling that might still be going on, can take - // up to 1100s. Plus some extra time to be sure + // up to 1100ms. Plus some extra time to be sure SystemClock.sleep(2000); }