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
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..ae3aed3899 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 1100ms. 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) {
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();
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 2f49e78c99..fe4ad3c65a 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,15 +124,27 @@ 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 1100ms. Plus some extra time to be sure
+ SystemClock.sleep(2000);
}
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");
}
+
+ // 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 1100ms. 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) {
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()");