nightscout / Trio

MIT License
49 stars 154 forks source link

Duplicated carb entries #175

Closed pheltzel closed 1 month ago

pheltzel commented 2 months ago

--Added 30g of carbs at 5:58 a.m. on May 11 (log attached). --But 2 entries appeared in the History screen in Trio

IMG_9008 IMG_9009

I deleted the second errant entry. So sorry, don't have a screenshot for that. Should have captured that first.

--Running Trio v0.1.0 --Branch: dev6f862aa --Omnipod Dash, G7

log-dupe-carb-entry.txt

This may be an intermittent bug -- and possibly only a display issue. Same issue was reported here in the iAPS Github Issues area and may be related to writing to Health:

https://github.com/Artificial-Pancreas/iAPS/issues/450

A potential fix was suggested here: https://github.com/Artificial-Pancreas/iAPS/pull/564

Could be user error, but I'm pretty sure I didn't enter this twice.

I still have iAPS 4 on my iPhone 15, not sure if that could be related. I've been seeing how it differs from what Trio advises.

But I've experienced the bug reported above (Issue 450 in iAPS), and it was thought to be Apple Health related, so I turned it off. I've turned it off in Trio now as well.

bjornoleh commented 2 months ago

I took a chance and assigned this to @AndreasStokholm, as he did battle with some AppleHealth issues 😄 I don’t know if that’s the issue here though.

dnzxy commented 2 months ago

iAPS "fix" via 564 is definitely not a fix.

Your logs show these 4 entries around that time:

  1. seems to be the actual entry, not at 5:58 but at 5:57. Your screenshot does not show if you entered multiple entries, so this is just a guessing game which timestamp is the actual time of entry or if there were multiple entries. 2024-05-11T05:57:04-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([1, "663f40c240a0bad0c3995100", true]))

  2. The NS layer in the app is trying to upload treatments to NS, while HealthKit is trying to save/sync samples and runs into an error. It then saves 30g to HK again. 2024-05-11T05:58:35-0400 [Nightscout] NightscoutManager.swift - uploadTreatments(_:fileToSave:) - 646 - DEV: Treatments uploaded 2024-05-11T05:58:35-0400 [Service] HealthKitManager.swift - save(samples:) - 231 - DEV: Failed to store carb entry in HealthKit Store! 2024-05-11T05:58:35-0400 [Service] HealthKitManager.swift - save(samples:) - 232 - DEV: Array of HKObjects to save cannot be empty 2024-05-11T05:58:40-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([true, "569FFA8C-013F-4869-93C0-4972C8586CBF", 1])) 2024-05-11T05:58:40-0400 [ApsManager]

  3. The next cycle, when HK does sync, it shows two 30g entries 2024-05-11T06:02:28-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([1, "569FFA8C-013F-4869-93C0-4972C8586CBF", true])) 2024-05-11T06:02:28-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([true, "663f40c240a0bad0c3995100", 1]))

For me this looks like two entries 1min apart and after another, but just a wild guess here.

pheltzel commented 2 months ago

Regarding your comments of it being a "guessing game," I was alarmed to see 2 30g entries when I had entered one, which I did not realize until later. So I immediately deleted one of the entries concerned I might be getting automatic, unwanted doses. Capturing for GH was not the first thing on my mind, sorry.

dnzxy commented 2 months ago

Guessing game on my part as I am not sure why the log shows different timestamps, not yours Paul. Sorry should have clarified that. You made no mistake 😊

Do you remember if the UI maybe seemed unresponsive and you tapped the save button twice or something like that? 🤔

dsnallfot commented 2 months ago

iAPS "fix" via 564 is definitely not a fix.

Your logs show these 4 entries around that time:

  1. seems to be the actual entry, not at 5:58 but at 5:57. Your screenshot does not show if you entered multiple entries, so this is just a guessing game which timestamp is the actual time of entry or if there were multiple entries. 2024-05-11T05:57:04-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([1, "663f40c240a0bad0c3995100", true]))
  2. The NS layer in the app is trying to upload treatments to NS, while HealthKit is trying to save/sync samples and runs into an error. It then saves 30g to HK again. 2024-05-11T05:58:35-0400 [Nightscout] NightscoutManager.swift - uploadTreatments(_:fileToSave:) - 646 - DEV: Treatments uploaded 2024-05-11T05:58:35-0400 [Service] HealthKitManager.swift - save(samples:) - 231 - DEV: Failed to store carb entry in HealthKit Store! 2024-05-11T05:58:35-0400 [Service] HealthKitManager.swift - save(samples:) - 232 - DEV: Array of HKObjects to save cannot be empty 2024-05-11T05:58:40-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([true, "569FFA8C-013F-4869-93C0-4972C8586CBF", 1])) 2024-05-11T05:58:40-0400 [ApsManager]
  3. The next cycle, when HK does sync, it shows two 30g entries 2024-05-11T06:02:28-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([1, "569FFA8C-013F-4869-93C0-4972C8586CBF", true])) 2024-05-11T06:02:28-0400 [Service] HealthKitManager.swift - save(samples:) - 225 - DEV: Stored carb entry 30 g in HealthKit Store! Metadata: Optional(Dictionary.Values([true, "663f40c240a0bad0c3995100", 1]))

For me this looks like two entries 1min apart and after another, but just a wild guess here.

The non-fix PR 564 was done by me by direct request from Jon (and then quickly merged to dev) to try to prevent that the setupTreatment function was triggered in parallell by 2 or more of the 4 observers triggering it and potentially writing duplicates to data table (see screenshot from DataTableStateModel). All testing and input around it at that time indicated that this was "just" a visual bug not affecting COB, but I cannot say that is definitely true.

IMG_3709

As you see in the issue I also clearly state that its a really long shot that this would help, and I'm glad that you now clearly confirmed that it do not help at all, since there been no feedback from anyone (that I've seen) about it since I made the PR 😊

Also good this bug got attention again in Trio, and hope this is easy to make a proper fix for by you @dnzxy or @AndreasStokholm as soon as you have the time to look into it more 👍

pheltzel commented 2 months ago

Thanks, all.

I am fairly confident I did not enter the carbs twice, always possible is was user error, but I believe this is a bug I have experienced before with iAPS. And if you look at the report from a user here:

https://github.com/Artificial-Pancreas/iAPS/issues/450

The user shows screenshots of multiple entries happening at the same time that were not manually entered. I had seen this bug at around the same time he reported it when it happened to his son. So when I saw it yesterday when I woke up, it felt familiar. When you realize 60g has been entered vs. 30 and SMBs are occurring and you're already near BG, it gets your attention.

I've actually turned Health back on just to see if I might catch this again and capture all the related data. But it's intermittent--which I know is super annoying to try to recreate/diagnose. But I did want to report this, it was worrisome when I was getting SMBs and wasn't sure how much the system was planning to give me. Whether it's a display issue, possibly, might be clearer from my log, if the estimate of how much insulin to be delivered near that time is clear. I sent a clip of the log with the initial bug report thinking that would be helpful to get right to the time it happened, but I have the entire thing.

dnzxy commented 2 months ago

Could you check if your pumphistory24h-zoned.json and carbhistory.json are still intact and show the time where this happened, please? If so; please just add it to the issue 😊 if it’s present in carb history and we can pinpoint additional dosing to the entries, then it’s definitely not just a UI glitch. If not, then it’s luckily just a glitch.

Maybe @avouspierre can have a look at this, as he has worked in the HK layer more than us others back when he was actively contributing to iAPS.

pheltzel commented 2 months ago

I grabbed those files this morning but unfortunately they only seem to go back to yesterday afternoon, well after the entries occurred.

carbhistory.json pumphistory-24h-zoned.json

avouspierre commented 2 months ago

My implementation was very naive without a very strong management of the concurrency 😫.

In this case, the log showed the tentative of HK upload a new glucose value at 5:57:04. The app went in background. And a strange error occurs with HK uploads at 5:57:37. Next a second tentative is done at 5:58:40.. . When the determinebasal responded at 5:58:40, the suggestion info wrote COB : 60.. so the "duplicate carbs" was created before.

dnzxy commented 2 months ago

What do you mean by "tentative"?

The next cycle definitely shows 2 entries, and HK does also sync for 2 entries at 6:02. I didn't check the 5:58 cycle, good catch!

avouspierre commented 2 months ago

A other hypothese will be that the app "analyse" the NS carbs as a new value of carbs. So Trio adds carbs > trio sends to NS > Trio fetches NS > trio adds as a new carb (as a duplicate).

Do you have the content of the "duplicate" carb in NS ?

bjornoleh commented 2 months ago

I think that deleting one of the entries from the app would have deleted that one from NS as well. So probably nothing to find now.

pheltzel commented 2 months ago

Unfortunately that's right. I ran the NS report for that time period and only one 30g entry appears.

bjornoleh commented 2 months ago

Depending on what NS solution is being used, there could possibly be something in NS logs (Papertrail on Heroku etc).

pheltzel commented 2 months ago

It's NS Pro.

https://xxxxxx.my.nightscoutpro.com/

pheltzel commented 2 months ago

Just a question: The bug reported in Artificial-Pancreas/iAPS#450 above in the thread included screenshots and logs.

Is Trio at this point diverged to the point that addressing the issue as it was reported then, using those logs, would not also address the bug if it exists in Trio? That use did a nice job of collecting data foe the report. I had this happen to me using iAPS so I looked up that report at the time.

bjornoleh commented 2 months ago

It's NS Pro.

https://xxxxxx.my.nightscoutpro.com/

Ok, thanks. I don’t need to see your NS url, and I noticed I could edit your post, so I anonymised the url for you :-)

You could ask the provider if they retain any logs for your NS instance. Chances are they don’t, but it doesn’t hurt to ask :-)

dnzxy commented 2 months ago

Pretty sure that Andy would help you in retrieving those logs if you ask him via a ticket 😊

dsnallfot commented 2 months ago

A other hypothese will be that the app "analyse" the NS carbs as a new value of carbs. So Trio adds carbs > trio sends to NS > Trio fetches NS > trio adds as a new carb (as a duplicate).

Do you have the content of the "duplicate" carb in NS ?

Shouldn't carbs “enteredBy” Trio in NS always be filtered out and never fetched by Trio? NightscoutAPI CarbsEntry NightscoutTreatment
image image image
pheltzel commented 2 months ago

Will do.

Paul Heltzel

http://heltzel.pressfolios.com/ https://www.linkedin.com/in/paul-heltzel-9175b61/

On Mon, May 13, 2024 at 7:20 AM Deniz Cengiz @.***> wrote:

Pretty sure that Andy would help you in retrieving those logs if you ask him via a ticket 😊

— Reply to this email directly, view it on GitHub https://github.com/nightscout/Trio/issues/175#issuecomment-2107313165, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAI4OJB7Q27Q4YEN74JLI33ZCCOZTAVCNFSM6AAAAABHR6RUP6VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMBXGMYTGMJWGU . You are receiving this because you authored the thread.Message ID: @.***>

avouspierre commented 2 months ago

Shouldn't carbs “enteredBy” Trio in NS always be filtered out and never fetched by Trio?

yes...that's why I wanted to know if the enteredBy was correct in NS...

dsnallfot commented 2 months ago

For what it's worth: I looked into the log_prev posted in issue 450 again. Lots of NS SSL errors as expected (as mentioned by the OP that the school was blocking connection to NS). But what I wanted to find out is that if the duplicated 58g entries never added up to more than 58g in COB at any point. And as far as I can see it seems to only have registered 1 entry of 58g COB (even if data table and AH shows 6-8 entries)

avouspierre commented 2 months ago

Thanks @dsnallfot.... so the issue is not the same because in this case, the COB in derterminebasal was "duplicated".

itsmojo commented 2 months ago

Not sure if this is another example of this problem or something else. On 5/14/24 I had an incident where I wanted to log some food with carbs, fats & proteins, but hitting Save and continue wasn’t taking the app to the next screen after multiple attempts. It appeared as if the Trio app was locked up. I evidently got out of that screen (using Close? I believe, but I’m not sure), but then I found that I had created many duplicate carb entries (I’d guess 70 - ~7 with my future carbs for each of my maybe 10 attempts to try to Save and continue with no response) that had to all be manually deleted. Unfortunately I was in a conversation & in a bit of a rush to recover when this happened and didn’t grab any screen shots or take careful mental notes of the details. I was running a version of Trio that was cloned on May 11 at 2 pm PDT at the time of this incident.

pheltzel commented 2 months ago

Thanks @itsmojo (also nice to see you again!) This absolutely be user error.

One thing I mentioned in the original post was that I had a functioning version of iAPS 4 on my phone at the time. I was surprised to see at one point that entries made in iAPS would show up in Trio. I don't think that happened here -- it was before 6 a.m. and a lot of is possible -- but I wanted to mention.

I also raised this issue because I had definitely seen multiple errant carb entries in iAPS that I did not input. That was confirmed by another user who reported the same issue at the same time with his kid--there were many, many errant entries for them, at the same time. My initial thought was: Are Health and Nightscout somehow double counting? Both were on, and like I said, I had seen it before. And I had iAPS on there still, potentially talking to NS and Health, though not connected to a pod, of course. It's possible I mixed a mean margarita of competing possible data entries.

So I am asking Andy to send my log from this time to see if that sheds any light. I know I didn't double tap this time, but it's totally possible I still screwed it up. Again, I had experienced double counting in iAPS and just wanted to make sure that isn't happening also in Trio.

itsmojo commented 2 months ago

This absolutely be user error.

I disagree. The app should not lock up and it certainly should not continue to add duplicate carb entries each time the "Save and continue" button is pressed if it does freeze up trying to save a carb entry. Sounds it could a different issue than the duplicate carb entry issue originally reported here though.

pheltzel commented 2 months ago

If it's error, it would be mine. If you add carbs, tap Save and Continue, then do it again, you get 2 carb entries in History.

But I don't think I did that. I think 2 entries showed up when only 1 was entered. And that happened to me in iAPS 3, a couple months ago.

pheltzel commented 2 months ago

image

It surprised me to see carb entries made in Trio appear in the iAPs History. This screenshot of the iAPS History shows carb entries made today in Trio.

marionbarker commented 2 months ago

I see this as well but with Loop carb entries showing in Trio. I use Loop but also have Trio on the phone (connected to pump simulator and using Nightscout as a CGM). I have Apple Health turned off. Trio must be downloading my carbs (uploaded by Loop) from Nightscout.

pheltzel commented 2 months ago

Ah, that's interesting. I have a copy of the latest iAPS on my phone but not set up. And though most of the settings are the defaults, my Nightscout info is there. Basal, CR, ISF are whatever you see as a new user, but it saved my NS URL and password.

dsnallfot commented 2 months ago

Ok folks.

It seems like there is at least three aspects to this duplicate carbs that needs to be fixed (the first two possible easier to fix than the third):

  1. Save button in meal view should probably be deactivated after tapping it the first time (to block potential double tapping before entering bolus view when app response is slow for whatever reason)?

  2. Nightscout fetch of treatments entered by other uploaders/in careportal (carbs/temp targets) should be possible for the user to enable/disable by toggle in settings, to avoid not expected carbs from Loop or iAPS etc showing up as it does today by default, as mentioned by @marionbarker and @pheltzel above. Treatments entered by Trio are already filtered out from fetching from NS and should never show up as duplicates in Trio. (I think @Sjoerd-Bo3 is working on the enable/disable fetching toggle?)

  3. Figure out why duplicates sometimes are created in datatable and apple health (but seemingly not affecting COB/calculations) and preventing this. (This is what I tried to address in the fix 564 that @dnzxy have concluded does not help at all).

  4. Maybe more aspects to this that I’ve not identified

dnzxy commented 2 months ago

Good summary.

I suspect No. 1 is an issue with I/O latency around JSON files that makes the UI unresponsive and possibly data races / race conditions - there are many of those in the current backend. I don’t think this can really be addressed with the current state of the app and is more so addressable when a more far reaching rewrite of the backend is introduced 😊

That’s also why we‘ve concluded that No. 3 isn’t a fix, as it just puts stuff on a different queue, but maybe a bandaid to those data races / race conditions / thread unsafe processes. You did rightfully describe it as a „maybe fix, needs testing“ in the PR, which is on point 👍😅

I don’t think that allowing other apps to influence Trio is a thing we‘d want, so No. 2 should probably not only be toggleable, but disallowed. Filtering for an enteredBy is probably the fix for this portion of the bug.

While this very much looks to be an actual bug, I‘ve personally never come across it in almost a year of using iAPS / Trio, so not sure what type of contexts need to be in place for this to happen. Maybe older phone with limited memory? Paul, Joe, what phones are you using?

I also think that the issue of having other apps uploading to NS and Trio then fetching those carb entries is not really related to this issue (#175), but a different one, and we should probably record it as such and keep it separate from this one here.

dsnallfot commented 2 months ago

I've had it happen at least two times (that I've noticed it) last year on my son's iPhone 12 mini.

But since switching to iPhone 13 mini, disabling Apple health and applying that separate queue thing for setupTreatments() it had not occurred again.

Been trying to force it to occur in simulator with AH enabled (while testing the separate queue) without success. It's seems almost impossible to reproduce the bug since it's so infrequent.

dnzxy commented 2 months ago

It shouldn’t be related to AH, as iAPS/Trio does not read from AH (read as in include read samples upon storage to carb history to be added to COB to be dosed for), unless I am misremembering things.

dsnallfot commented 2 months ago

It shouldn’t be related to AH, as iAPS/Trio does not read from AH (read as in include read samples upon storage to carb history to be added to COB to be dosed for), unless I am misremembering things.

Yeah. iAPS/Trio only writes to AH. But my thinking was if the writing runs into errors, could that cause issues with retries or Trio freezing etc?

AndreasStokholm commented 2 months ago

That shouldn't be an issue no. If AH fails writing now it will not crash the app, but the AH reporting will be incorrect for that one write (which will in many cases show up later as the app is very verbose with what it writes and updates in AH).

Sorry for not responding to this ticket sooner @bjornoleh, I missed the notification 😬

itsmojo commented 2 months ago

@dnzxy My iPhone is a 15 Pro Max 512 GB running iOS 17.4.1. In the past I have occasionally noticed brief hangs trying to save in the meal view when running iAPS & Trio, but in this most recent incident it was much more prolonged hang.

bjornoleh commented 2 months ago

Speaking of hangs, I have noticed some that may or may not be related to the above. Just wanted to mention it in case there is something in common.

I typically have several builds on my phone for testing in sim mode, using different bundle IDs.

When opening one of these a long time since the last time it ran, it will typically hang initially. Usually, it will become responsive again after several seconds (10+ sec). I believe this is when there is no data from the last 24 hours in the log files (the files will contain old data at startup). Perhaps it’s related to purging the json files?

I have also had situations where the app never became responsive, and had to be uninstalled. This goes back to previous versions of the project (iAPS).

pheltzel commented 2 months ago

@dnzxy I'm using an iPhone 15 Pro/iOS 17.3.1/256GB.

I can document No. 2 @dsnallfot described as a PR if that's helpful to break these up. That one I can recreate and get screen captures of easily.

dnzxy commented 2 months ago

Okay I don’t think it’s phone / memory related then, as both you and Joe are running new and performant hardware. Bummer, I had hoped it’s due to lack of memory 🫠

If you could record a second issue, that would be super nice, thank you 🙏

tredair7 commented 1 month ago

I’m the OP of the duplicate carb bug entry. A user added this comment in Discord about it. Seems like it might be helpful, in case you all haven’t already seen it. IMG_2461

pheltzel commented 1 month ago

Andy was unable to provide the NS Pro logs, they aren't stored for very long.

If this happens again it would be good to capture asap the Trio log, screenshots of the dupe carbs in history, NS report and these files:

carbhistory.json pumphistory-24h-zoned.json

I tried entering carbs in iAPS 4 dev, with Health and my NS account connected in the app, but I'm no longer seeing carb entires made in iAPS appear in Trio.

I do see carb entries made in Trio appear in the iAPS history.

Stefan261288 commented 1 month ago

I had this happening to me few days back where I had entered carbs and was expecting to bolus. The app did not respond when I clicked "Save and continue", and I had ended up adding 50g of carbs 4 times before I realized there was something wrong. Obviously I did not bolus and I could quickly delete the extra carbs afterwards, but 200g of carbs would affect the automatic provisions of insulin.

If it happens again I will follow the instructions above to log it. This cannot be identified as a user error, and it does not have to do with carbs coming from other apps (I only enter data in Trio).

I agree with previous poster that somehow blocking carb entries would be a good way to ensure it does not happen. Possibly blocking duplicate carb entries for X seconds.

bjornoleh commented 1 month ago

That shouldn't be an issue no. If AH fails writing now it will not crash the app, but the AH reporting will be incorrect for that one write (which will in many cases show up later as the app is very verbose with what it writes and updates in AH).

Sorry for not responding to this ticket sooner @bjornoleh, I missed the notification 😬

I assigned this issue to you due to the impression that this was related to AH. That does not seem to be the case, so I will remove that assignment in case someone else wants to get busy with this :-)

MikePlante1 commented 1 month ago

@dsnallfot :

  1. Save button in meal view should probably be deactivated after tapping it the first time (to block potential double tapping before entering bolus view when app response is slow for whatever reason)?

I just submitted a PR for this: #248