Force settings refresh on next loop if get_settings had a failure

[jpcunningh]

If one of the read commands fails in get_settings and leaves a file in an invalid state, the loop won't correct the problem until it determines it is time to read the profile again. This PR will recognize the failure, and set the age of settings/profile.json and settings/settings.json to force get_settings to be called again. This is how I recovered from the loop failure below after it occurred for more than 20 minutes.

The pump-loop.log capture below illustrates the problem this is intended to fix. The failure is due to an empty ~/myopenaps/settings/basal_profile.json file when oref0-meal.js attempts to get the contents on line number 50. I believe this can only happen from a failure in get_settings since I was unable to locate any other place in the software that can delete the contents of basal_profile.json.

Starting oref0-pump-loop at Fri Aug 31 22:21:03 CDT 2018 with 4 second wait_for_silence:
Waiting up to 4 minutes for new BG: ...............glucose.json newer than pump_loop_completed

Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:24:13 CDT 2018
Preflight OK. Profile less than 60m old; Profile valid. Pump history updated through 2018-08-31T22:00:07-05:00; meal.json refreshed: {"carbs":0,"nsCarbs":0,"bwCarbs":0,"journalCarbs":0,"mealCOB":0,"currentDeviation":-5.27,"maxDeviation":0,"minDeviation":-2.45,"slopeFromMaxDeviation":0,"slopeFromMinDeviation":0,"allDeviations":[-5,-2,-2,-2,-2,-2],"lastCarbTime":0,"bwFound":false}
Listening for 3 s silence: Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:24:52 CDT 2018
Checking that pump clock: "2018-08-31T22:24:17-05:00" is within 90s of current time: 2018-08-31T22:24:55-0500
Temp refreshed: monitor/temp_basal.json: {"duration":7,"temp":"absolute","rate":0.4}
{"carbs":0,"nsCarbs":0,"bwCarbs":0,"journalCarbs":0,"mealCOB":0,"currentDeviation":-5.27,"maxDeviation":0,"minDeviation":-2.45,"slopeFromMaxDeviation":0,"slopeFromMinDeviation":0,"allDeviations":[-5,-2,-2,-2,-2,-2],"lastCarbTime":0,"bwFound":false}
Autotune exists! Hoorah! You can use microbolus-related features.
{"iob":-0.285,"activity":0.0007,"basaliob":-0.49,"bolusiob":0.205,"netbasalinsulin":-1.3,"bolusinsulin":2.3,"time":"2018-09-01T03:24:19.000Z","iobWithZeroTemp":{"iob":-0.285,"activity":0.0007,"basaliob":-0.49,"bolusiob":0.205,"netbasalinsulin":-1.3,"bolusinsulin":2.3,"time":"2018-09-01T03:24:19.000Z"},"lastBolusTime":1535762315000,"lastTemp":{"rate":0.4,"timestamp":"2018-08-31T22:00:07-05:00","started_at":"2018-09-01T03:00:07.000Z","date":1535770807000,"duration":25.2}}
{"delta":-9,"glucose":88,"noise":1,"short_avgdelta":-7.06,"long_avgdelta":-4.12,"date":1535772185243,"last_cal":0}
Autosens ratio: 1; Basal unchanged: 1.2; ISF unchanged: 100; CR: 23.884
currenttemp: { duration: 7, temp: 'absolute', rate: 0.4 } lastTempAge: 25 m tempModulus: 2 m
SMB enabled due to enableSMB_always
Carb Impact: -8.6 mg/dL per 5m; CI Duration: 0 hours; remaining CI (~2h peak): 0 mg/dL per 5m
UAM Impact: -8.6 mg/dL per 5m; UAM Duration: 0 hours
minPredBG: 58 minIOBPredBG: 48 minZTGuardBG: 87 minUAMPredBG: 44 avgPredBG: 87 COB: 0 / 0
minGuardBG 43 projected below 75 - disabling SMB
BG projected to remain above 110 for 0 minutes
BG projected to remain above 75 for 10 minutes
naive_eventualBG: 117 bgUndershoot: -42 zeroTempDuration: 10 zeroTempEffect: 20 carbsReq: -15
2018-09-01T03:25:04.743Z
Checking deliverAt: 2018-09-01T03:25:04.743Z is within 1m of current time: Fri Aug 31 22:25:04 CDT 2018
and that smb-suggested.json is less than 1m old
enact/smb-suggested.json: {"temp":"absolute","bg":88,"tick":-9,"eventualBG":94,"insulinReq":0,"reservoir":"37.45\n","deliverAt":"2018-09-01T03:25:04.743Z","sensitivityRatio":1,"COB":0,"IOB":-0.285,"duration":30,"rate":0}
"COB: 0, Dev: -23, BGI: 0, ISF: 100, CR: 23.88, Target: 110, minPredBG 58, minGuardBG 43, IOBpredBG 65; minGuardBG 43<75"
IOB: [88,80,72,66,60,55,51,48,46,44,43,43,44,44,45,46,47,47,48,49,50,51,51,52,53,54,54,55,56,56,57,58,58,59,60,60,61,61,62,62,63,63,63,64,64,64,65]
ZT:  [88,88,87,87,88,88,89,90,91,92,94,96,98,100,103,105,108]
Temp refreshed: monitor/temp_basal.json: {"duration":7,"temp":"absolute","rate":0.4}
enact/smb-enacted.json: "Rate: 0 Duration: 30"
Checking pump status (suspended/bolusing): {"status":"normal","bolusing":false,"suspended":false}
Temp refreshed: monitor/temp_basal.json: {"duration":30,"temp":"absolute","rate":0}
No bolus needed. Settings less than 30 minutes old. Refreshing pumphistory because: enacted, Full history refresh failed.
Retry 1 of read_full_pumphistory
Full history refresh failed.
Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:26:00 CDT 2018
Retry 2 of read_full_pumphistory
Full history refresh failed.
Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:26:27 CDT 2018
Retry 3 of read_full_pumphistory
Full history refresh failed.
Couldn't read_full_pumphistory - continuing
Your instance of oref0 [0.7.0-dev, rig-running-branch] is up-to-date.
Your instance of oref0 [0.7.0-dev, rig-running-branch] is up-to-date with upstream.
Completed oref0-pump-loop at Fri Aug 31 22:26:44 CDT 2018


Starting oref0-pump-loop at Fri Aug 31 22:27:03 CDT 2018 with 23 second wait_for_silence:
Waiting up to 4 minutes for new BG: ...........glucose.json newer than pump_loop_completed

Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:29:43 CDT 2018
Preflight OK. Profile less than 60m old; Profile valid. Full history refresh failed.
Couldn't invoke_pumphistory_etc - continuing
Retry 1 of refresh_pumphistory_and_meal
Pump history updated through 2018-08-31T22:24:31-05:00; meal.json Could not parse input data:  SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at Object.<anonymous> (/root/src/oref0/bin/oref0-meal.js:50:38)
    at Module._compile (module.js:652:30)
    at Object.Module._extensions..js (module.js:663:10)
    at Module.load (module.js:565:32)
    at tryModuleLoad (module.js:505:12)
    at Function.Module._load (module.js:497:3)
    at Function.Module.runMain (module.js:693:10)
    at startup (bootstrap_node.js:191:16)
    at bootstrap_node.js:612:3
{ "carbs": 0, "mealCOB": 0, "reason": "Could not parse input data" }
{"carbs":0,"nsCarbs":0,"bwCarbs":0,"journalCarbs":0,"mealCOB":0,"currentDeviation":-5.27,"maxDeviation":0,"minDeviation":-2.45,"slopeFromMaxDeviation":0,"slopeFromMinDeviation":0,"allDeviations":[-5,-2,-2,-2,-2,-2],"lastCarbTime":0,"bwFound":false}
Couldn't check_cp_meal - continuing
Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:30:49 CDT 2018
Retry 2 of refresh_pumphistory_and_meal
Pump history update failed. Last record 2018-08-31T22:24:31-05:00
Couldn't invoke_pumphistory_etc - continuing
Listening: .No interfering pump comms detected from other rigs (this is a good thing!)
Continuing oref0-pump-loop at Fri Aug 31 22:31:24 CDT 2018
Retry 3 of refresh_pumphistory_and_meal
Pump history updated through 2018-08-31T22:24:31-05:00; meal.json Could not parse input data:  SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at Object.<anonymous> (/root/src/oref0/bin/oref0-meal.js:50:38)
    at Module._compile (module.js:652:30)
    at Object.Module._extensions..js (module.js:663:10)
    at Module.load (module.js:565:32)
    at tryModuleLoad (module.js:505:12)
    at Function.Module._load (module.js:497:3)
    at Function.Module.runMain (module.js:693:10)
    at startup (bootstrap_node.js:191:16)
    at bootstrap_node.js:612:3
{ "carbs": 0, "mealCOB": 0, "reason": "Could not parse input data" }
{"carbs":0,"nsCarbs":0,"bwCarbs":0,"journalCarbs":0,"mealCOB":0,"currentDeviation":-5.27,"maxDeviation":0,"minDeviation":-2.45,"slopeFromMaxDeviation":0,"slopeFromMinDeviation":0,"allDeviations":[-5,-2,-2,-2,-2,-2],"lastCarbTime":0,"bwFound":false}
Couldn't check_cp_meal - continuing
Couldn't refresh_pumphistory_and_meal
oref0-pump-loop failed. If pump and rig are close enough, this error usually self-resolves. Stand by for the next loop.
Unsuccessful oref0-pump-loop at Fri Aug 31 22:31:53 CDT 2018

[jpcunningh]

Rebased onto dev to resolve merge conflict.

[zgohr]

👍

[alimhassam]

Just noticed this pr. Thanks for fixing this. The situation occurred to me a couple of days ago, so looking forward to having a proper fix for the problem

[jpcunningh]

@scottleibrand, we've been running this now a couple of weeks with good success. I think it's ready to merge unless you have questions / comments.

[scottleibrand]

I understand the logic of running all the commands and then setting the profile age to force a retry if they fail. But why suppress failures of earlier commands by setting success to 1 on each subsequent one? Doesn’t that make the last command the only one we’re actually checking success of?

[jpcunningh]

The single equal in the double brackets is a string based test instead of assignment. Once one command fails, it bails out of running the remaining commands and sets it to force the retry.

For readability, I'll change it to -eq, a numeric based test. Thanks!

[scottleibrand]

Ah, ok. That’s an nasty confusing bash-ism: thanks for changing it.