Bolus not recorded in active insulin, extra insulin delivered

[joshandeliana]

Very typical breakfast this morning for my daughter: 40 carbs, carb ratio means 3.45 units and I give an extra unit to superbolus it. I do not remember watching for the orange circle when I dosed. I did notice the 4.45 in Nightscout. Next thing I see is loop did two autoboluses. I checked the active insulin screen (which I thought is the definitive answer on whether a bolus happened) and saw no 7:10am bolus. So I added the rest of what should have been delivered and she went urgent low (gave extra carbs right away). The IOB in Nightscout matches the active insulin report, but symptoms do not. Hopefully I’ve provided enough information. Will definitely be watching for the orange circle from now on but interested to know what happened here?

[joshandeliana]

I did try to attach an issue report, not sure if it went through.

[ps2]

The issue report does not appear to be attached here. The issue report would be very helpful here. Also, if you can export the critical device logs, that might help as well.

[joshandeliana]

Loop Report 2023-03-10 07 45 18-05 00.md

[joshandeliana]

Figured out how to add it, sorry for the delay! Looper and loop phone are at school until 4pm. Please give me instructions to generate any additional reports and I will as soon as I can. I did see a recent issue report that looked very similar although they were more skeptical and stopped the rest of the additional insulin. I did need to correct with a full 40 carbs, so clearly the dose was delivered initially even though it did not show in the IOB or insulin delivery screen. A similarity I noticed with the other issue report is that we both changed the recommended bolus, but that's something I do all the time and have never had a problem.

[joshandeliana]

Export-20230310T210553Z.zip

[ps2]

Thanks @joshandeliana ! Sorry you had issues, and I'm glad everyone is safe. Thank you for sharing your logs. I spent a couple hours digging into this tonight. You're correct that the 4.45 bolus was delivered. I could see in the logs that Loop successfully sent the command to the pod, and the pod responded properly. After a lot of code review, I've discovered a bug that I believe is the cause of this "disappearing" bolus. It's a very subtle bug, and requires a very specific set of circumstances to trigger.

The bolus was delivered at 2023-03-10 12:11:24 (UTC time). Loop tracks how long it expects a bolus to take to deliver. In this case, 4.45 U at a rate of 0.05 U every 2 seconds, should take 2 minutes and 58 seconds. By a crazy coincidence, your pod's communication reset with a timing such that Loop requested the status exactly 2 minutes and 58 seconds later. The pod at this point responded that no bolus was being delivered. When Loop is tracking a bolus, and the pod reports that no bolus is ongoing, normally Loop assumes the bolus is complete, and sends it to finalized storage. However, there is a bug in the code if Loop thinks there is still remaining time on the bolus, it will mark it as unfinished, which ultimately caused it to be eventually dropped. For this set of events to happen, the status request has to happen in the short time interval (in this case < 1s) between the actual bolus completion and Loop's estimation of the completion.

Loss of dosing information is a very serious issue, and I am working on a fix to prevent this from happening in the future. However, I think the specific timing needed should make this kind of event only a rare occurrence.

Thanks for helping to improve Loop!

# Successful 4.45U Bolus
2023-03-10 12:11:24 +0000 send    Message(1744d21f seq:07 [SetInsulinScheduleCommand(nonce:1229869870, bolus(units: 4.45, timeBetweenPulses: 2.0, table: OmniKitPacketParser.BolusDeliveryTable(entries: [InsulinTableEntry(segments:1, pulses:89, alternateSegmentPulse:false)]))), BolusExtraCommand(units:4.45, timeBetweenPulses:2.0, extendedUnits:0.0, extendedDuration:0.0, acknowledgementBeep:false, completionBeep:false, programReminderInterval:0.0)])
# Response indicating bolusing
2023-03-10 12:11:25 +0000 receive Message(1744d21f seq:08 [StatusResponse(deliveryStatus:Bolusing with temp basal, progressStatus:Normal, timeActive:1 day plus 14:43, reservoirLevel:51.15, delivered:57.0, bolusNotDelivered:4.45, lastProgrammingMessageSeqNum:7, alerts:No alerts)])

# Get status 2m, 58s later… exactly the amount of time we expect the bolus to take to deliver???

2023-03-10 12:14:23 +0000 send    Message(1744d21f seq:09 [GetStatusCommand(normal)])

# Response shows no bolus running

2023-03-10 12:14:23 +0000 receive Message(1744d21f seq:10 [StatusResponse(deliveryStatus:Temp basal running, progressStatus:Normal, timeActive:1 day plus 14:46, reservoirLevel:51.15, delivered:61.45, bolusNotDelivered:0.0, lastProgrammingMessageSeqNum:7, alerts:No alerts)])

[blameitonben]

👏!

…

________________________________ From: Pete Schwamb ***@***.***> Sent: Saturday, March 11, 2023 7:03:20 PM To: LoopKit/Loop ***@***.***> Cc: Subscribed ***@***.***> Subject: Re: [LoopKit/Loop] Bolus not recorded in active insulin, extra insulin delivered (Issue #1941) Thanks @joshandeliana<https://github.com/joshandeliana> ! Sorry you had issues, and I'm glad everyone is safe. Thank you for sharing your logs. I spent a couple hours digging into this tonight. You're correct that the 4.45 bolus was delivered. I could see in the logs that Loop successfully sent the command to the pod, and the pod responded properly. After a lot of code review, I've discovered a bug that I believe is the cause of this "disappearing" bolus. It's a very subtle bug, and requires a very specific set of circumstances to trigger. The bolus was delivered at 2023-03-10 12:11:24 (UTC time). Loop tracks how long it expects a bolus to take to deliver. In this case, 4.45 U at a rate of 0.05 U every 2 seconds, should take 2 minutes and 58 seconds. By a crazy coincidence, your pod's communication reset with a timing such that Loop requested the status exactly 2 minutes and 58 seconds later. The pod at this point responded that no bolus was being delivered. When Loop is tracking a bolus, and the pod reports that no bolus is ongoing, normally Loop assumes the bolus is complete, and sends it to finalized storage. However, there is a bug in the code if Loop thinks there is still remaining time on the bolus, it will mark it as unfinished, which ultimately caused it to be eventually dropped. For this set of events to happen, the status request has to happen in the short time interval (in this case < 1s) between the actual bolus completion and Loop's estimation of the completion. I am working on a fix that will prevent this from happening in the future. Thanks for helping to improve Loop! — Reply to this email directly, view it on GitHub<#1941 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/ACWNLOY7UC6M2W7UEYMLEXDW3U4HRANCNFSM6AAAAAAVWNYXEI>. You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[joshandeliana]

Thank you Pete for the timely and thorough explanation.

I thought I was being so clever by trusting the active insulin log and not nightscout. I hope that if it hadnt been the school morning rush I would have been more cautious and waited to see how blood sugar responded before giving more insulin. It did take 50+ grams of extra carbs to get her back on track, some of which I had to deliver at the nurse's office after taking her to school. I was a bit nervous to tell the school nurse what was happening as I dont want them asking any questions about loop. I now feel very confident if there are any questions, because commercial systems have glitches too, but you dont get to troubleshoot with the software's creators in those situations!

Very grateful for loop and all of its contributors!

[joshandeliana]

Issue 1886 is the other one I found that looked similar, in case this is helpful.

[Blanderson86]

Hi,

I have had this happen to me/my sons teachers about 4 times the last couple of months. Most recently today. I can attach my issue report

More detail from today on facebook
https://www.facebook.com/groups/TheLoopedGroup/permalink/3338347903048519/

[Blanderson86]

Loop Report 2023-03-12 205531Z.zip

[ps2]

A fix for this just landed in dev. I would appreciate any testing that anyone is able to do with this update. You can test by building the latest dev. Please join the loop zulip chat if you're not already there: (https://loop.zulipchat.com/)