Dev not sending TBR to NS

[Foxy7]

I migrated my wife from Master to Dev last weekend and since then NS no longer shows TBR rendered. Her NS version is 14.2.6.

e.g. there is no change from the profile basal rendered in NS but i don't believe this is a NS issue.

We're using the latest AIMI build, which is based off AAPS dev-g commit 14a329d however this issue has been persistent since i moved her over to Dev on Sunday 08Jan.

From what i can tell the NSClient module isn't pushing the TBR to NS, i can see Device Status, Profile Switches, SMBs etc all being sent, but not the TBR.

Most recent SMB 22:51 and TBR 22:55 treatments:

on the NSClient view, i can see it's adding the treatment for the SMB at 22:51, but it's not doing the same for the TBR at 22:55, but it does send the device status.

one futher thing that is new since moving to Dev, is the NSClient Queue is consistently growing and now showing +1500 items, as you can see top right in screenshot above. I've no idea what these are or how to view them. by comparison my kid who is still using Master and NS 14.2.6 has a queue of zero items.

here's some parts of the log file, which shows a that TBR hasn't updated since my wife started using Dev last Sunday, the TBR epco ms is the time i started Dev on her phone Sun Jan 08 2023 08:57:10,

22:52:07.054 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedTemporaryBasals():510]: Loading TemporaryBasal data Start: 0 TemporaryBasal(id=1, version=1, dateCreated=1673168230344

in comparison the SMB time which is the correct last SMB Sat Jan 14 2023 22:51:52.

22:52:07.047 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedBoluses():121]: Loading Bolus data Start: 532 Bolus(id=532, version=1, dateCreated=1673736712218

22:52:07.044 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: PING received
22:52:07.046 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: QUEUE Resend started: Ping received
22:52:07.047 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedBoluses():121]: Loading Bolus data Start: 532 Bolus(id=532, version=1, dateCreated=1673736712218, isValid=true, referenceId=null, interfaceIDs_backing=InterfaceIDs(nightscoutSystemId=null, nightscoutId=63c331fea50e720004c6f9f0, pumpType=DANA_RS, pumpSerial=, temporaryId=null, pumpId=1673736676000, startId=null, endId=null), timestamp=1673736676000, utcOffset=0, amount=0.05, type=SMB, notes=null, isBasalInsulin=false, insulinConfiguration=null) forID: 533 
22:52:07.048 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedBoluses():132]: Ignoring Bolus. Only NS id changed: 533 
22:52:07.054 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedTemporaryBasals():510]: Loading TemporaryBasal data Start: 0 TemporaryBasal(id=1, version=1, dateCreated=1673168230344, isValid=true, referenceId=null, interfaceIDs_backing=InterfaceIDs(nightscoutSystemId=null, nightscoutId=null, pumpType=DANA_RS, pumpSerial=, temporaryId=null, pumpId=1673133721000, startId=null, endId=1673135436000), timestamp=1673133721000, utcOffset=0, type=NORMAL, isAbsolute=false, rate=0.0, duration=1715000) forID: 1 
22:52:07.068 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: QUEUE Resend ended: Ping received

i've picked a couple of lines out of the log file:

prior basal rate:

22:55:44.399 [DefaultDispatcher-worker-5] D/APS: [DetermineBasalAdapterAIMIJS.invoke():95]: Current temp:   {"temp":"absolute","duration":10,"rate":0.42,"minutesrunning":5}

initiated basal rate

22:55:44.451 [DefaultDispatcher-worker-5] D/APS: [LoopPlugin.applyTBRRequest():556]: applyAPSRequest: Rate: 0.90 U/h (300.00%) Duration: 30.00 min Reason: undefined. force basal because you receive 2 time max smb size : 10 minutes0.14999999999999997, 10m@0.42 Force Basal AIMI
22:55:44.451 [RxCachedThreadScheduler-42] D/WEAR: [DataLayerListenerServiceMobile.sendMessage():192]: sendMessage: /rx_bridge {"type":"info.nightscout.rx.weardata.EventData.SingleBg","timeStamp":1673736923219,"sgvString":"8.5","glucoseUnits":"mmol","slopeArrow":"→","delta":"+0.2","avgDelta":"+0.2","sgv":153.0,"high":180.0,"low":72.0}
22:55:44.452 [RxCachedThreadScheduler-42] D/WEAR: [DataLayerListenerServiceMobile.sendMessage():192]: sendMessage: /rx_bridge {"type":"info.nightscout.rx.weardata.EventData.Preferences","timeStamp":1673736944451,"wearControl":true,"unitsMgdl":false,"bolusPercentage":100,"maxCarbs":100,"maxBolus":6.0,"insulinButtonIncrement1":0.5,"insulinButtonIncrement2":1.0,"carbsButtonIncrement1":5,"carbsButtonIncrement2":10}
22:55:44.452 [RxCachedThreadScheduler-42] D/WEAR: [DataLayerListenerServiceMobile.sendMessage():192]: sendMessage: /rx_bridge {"type":"info.nightscout.rx.weardata.EventData.QuickWizard","entries":[]}
22:55:44.454 [DefaultDispatcher-worker-5] D/APS: [LoopPlugin.applyTBRRequest():619]: applyAPSRequest: setTempBasalAbsolute()
22:55:44.455 [DefaultDispatcher-worker-5] D/PUMPQUEUE: [CommandQueueImplementation.add():177]: Adding: CommandTempBasalAbsolute - TEMP BASAL 0.8999999999999999 U/h 30 min
22:55:44.455 [DefaultDispatcher-worker-5] D/APS: [LoopPlugin.invoke():454]: invoke end
22:55:44.455 [DefaultDispatcher-worker-5] D/WORKER: [LoggingWorker$doWork$2.invokeSuspend():29]: Worker result SUCCESS for class kotlinx.coroutines.UndispatchedCoroutine
22:55:44.459 [Thread-19067] D/PUMPQUEUE: [QueueThread.run():112]: connect
22:55:44.460 [Thread-19067] D/PUMP: [DanaRSPlugin.connect():163]: RS connect from: Connection needed
22:55:44.459 [CommandQueueImplementationHandler] D/PUMPQUEUE: [CommandQueueImplementation.notifyAboutNewCommand$lambda$6():213]: Starting new thread
22:55:44.461 [Thread-19067] D/PUMPBTCOMM: [BLEComm.connect():112]: Initializing BLEComm.
22:55:44.461 [RxCachedThreadScheduler-433] D/CORE: [UserEntryLoggerImpl$log$1.accept():56]: USER ENTRY: 14/01/2023 22:55:44 TEMP_BASAL Loop  [UnitPerHour(value=0.8999999999999999), Minute(value=30)]
22:55:44.464 [Thread-19067] D/PUMPBTCOMM: [BLEComm.connect():141]: Trying to create a new connection from: Connection needed
22:55:44.476 [Thread-19067] D/PUMPBTCOMM: [BLEComm.setCharacteristicNotification():280]: setCharacteristicNotification
22:55:44.494 [DefaultDispatcher-worker-5] D/WORKER: [LoggingWorker$doWork$2.invokeSuspend():29]: Worker result SUCCESS for class kotlinx.coroutines.UndispatchedCoroutine

could this line in this next section explain the issue? usually zero is false (at least when i use it in excel..)

22:55:52.031 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketAPSBasalSetTemporaryBasal.handleMessage():47]: Set APS temp basal start result: 0

followed by the failure to load to NS

22:55:52.802 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedTemporaryBasals():510]: Loading TemporaryBasal data Start: 0 TemporaryBasal(id=1, version=1, dateCreated=1673168230344, isValid=true, referenceId=null, interfaceIDs_backing=InterfaceIDs(nightscoutSystemId=null, nightscoutId=null, pumpType=DANA_RS, pumpSerial=, temporaryId=null, pumpId=1673133721000, startId=null, endId=1673135436000), timestamp=1673133721000, utcOffset=0, type=NORMAL, isAbsolute=false, rate=0.0, duration=1715000) forID: 1 

22:55:50.482 [Thread-19067] D/PUMPQUEUE: [QueueThread.run():121]: connection time 6s
22:55:50.483 [Thread-19067] D/PUMPQUEUE: [QueueThread.run():127]: performing TEMP BASAL 0.8999999999999999 U/h 30 min
22:55:50.484 [Thread-19067] D/PUMP: [DanaRSPlugin.setTempBasalAbsolute():374]: setTempBasalAbsolute: currently running
22:55:50.485 [Thread-19067] D/CORE: [TemporaryBasalStorageImpl.add():23]: Stored temporary basal info: TemporaryBasal(timestamp=1673736950485, duration=1800000, rate=300.0, isAbsolute=false, type=NORMAL, id=0, pumpId=0, pumpType=USER, pumpSerial=)
22:55:50.485 [Thread-19067] D/PUMP: [DanaRSPlugin.setTempBasalAbsolute():391]: setTempBasalAbsolute: Setting temp basal 300% for 30 minutes (doLowTemp || doHighTemp)
22:55:50.485 [Thread-19067] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.<init>():22]: New message
...
22:55:50.832 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():47]: ErrorState: NONE
22:55:50.832 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():49]: Pump suspended: false
22:55:50.832 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():50]: Temp basal in progress: true
22:55:50.832 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():51]: Extended in progress: false
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():52]: Dual in progress: false
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():53]: Daily units: 21.1
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():54]: Max daily units: 50
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():55]: Reservoir remaining units: 64.6
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():56]: Battery: 75
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():57]: Current basal: 0.3
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():58]: Temp basal percent: 140
22:55:50.833 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketGeneralInitialScreenInformation.handleMessage():59]: Extended absolute rate: 0.0
22:55:50.833 [Thread-19067] D/PUMPCOMM: [DanaRSPacketBasalSetCancelTemporaryBasal.<init>():13]: Canceling temp basal
22:55:50.834 [Thread-19067] D/PUMPBTCOMM: [BLEComm.sendMessage():779]: >>>>> BASAL__CANCEL_TEMPORARY_BASAL B2 62  
22:55:51.129 [binder:29236_F] D/PUMPBTCOMM: [BLEComm.processMessage():859]: <<<<< BASAL__CANCEL_TEMPORARY_BASAL B2 62 00 
22:55:51.129 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketBasalSetCancelTemporaryBasal.handleMessage():19]: Result OK
22:55:51.632 [Thread-19067] D/PUMPCOMM: [DanaRSPacketAPSBasalSetTemporaryBasal.<init>():18]: New message: percent: 300
22:55:51.632 [Thread-19067] D/PUMPCOMM: [DanaRSPacketAPSBasalSetTemporaryBasal.<init>():28]: APS Temp basal start percent: 300 duration 15 min
22:55:51.633 [Thread-19067] D/PUMPBTCOMM: [BLEComm.sendMessage():779]: >>>>> BASAL__APS_SET_TEMPORARY_BASAL B2 C1  2C 01 96 
22:55:52.029 [binder:29236_F] D/PUMPBTCOMM: [BLEComm.processMessage():859]: <<<<< BASAL__APS_SET_TEMPORARY_BASAL B2 C1 00 
22:55:52.031 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketAPSBasalSetTemporaryBasal.handleMessage():47]: Set APS temp basal start result: 0
22:55:52.796 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: PING received
22:55:52.797 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: QUEUE Resend started: Ping received
22:55:52.802 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedTemporaryBasals():510]: Loading TemporaryBasal data Start: 0 TemporaryBasal(id=1, version=1, dateCreated=1673168230344, isValid=true, referenceId=null, interfaceIDs_backing=InterfaceIDs(nightscoutSystemId=null, nightscoutId=null, pumpType=DANA_RS, pumpSerial=, temporaryId=null, pumpId=1673133721000, startId=null, endId=1673135436000), timestamp=1673133721000, utcOffset=0, type=NORMAL, isAbsolute=false, rate=0.0, duration=1715000) forID: 1 
22:55:52.806 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedGlucoseValues():377]: Loading GlucoseValue data Start: 1886 GlucoseValue(id=1887, version=0, dateCreated=1673736935262, isValid=true, referenceId=null, interfaceIDs_backing=null, timestamp=1673736932123, utcOffset=0, raw=0.0, value=153.0, trendArrow=FLAT, noise=null, sourceSensor=DEXCOM_G6_G5_NATIVE_XDRIP) forID: 1887 
22:55:52.809 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedDeviceStatuses():480]: Loading DeviceStatus data Start: 1933 DeviceStatus(id=1934, interfaceIDs_backing=null, timestamp=1673736944432, utcOffset=0, device=openaps://samsung SM-S901B, pump={"battery":{"percent":75},"status":{"status":"normal","timestamp":"2023-01-14T22:51:23.747Z"},"extended":{"Version":"3.1.0.3-dev-g-AIMI-7dc80c1206-2023.01.13","LastBolus":"14\/01\/2023 22:51","LastBolusAmount":0.05,"TempBasalAbsoluteRate":0.42,"TempBasalStart":"14\/01\/2023 22:51","TempBasalRemaining":10,"BaseBasalRate":0.3,"ActiveProfile":"aimi_Fiasp_20230114"},"reservoir":64,"clock":"2023-01-14T22:55:44.432Z"}, enacted=null, suggested={"reason":"undefined. force basal because you receive 2 time max smb size : 10 minutes0.14999999999999997, 10m@0.42 Force Basal AIMI","temp":"absolute","duration":30,"rate":0.8999999999999999,"timestamp":"2023-01-14T22:55:44.429Z"}, iob={"iob":0.284,"basaliob":0.107,"activity":0.0019,"time":"2023-01-14T22:55:44.429Z"}, uploaderBattery=28, configuration={})
22:55:52.811 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: ADD devicestatus Sent PairDeviceStatus {"created_at":"2023-01-14T22:55:44.432Z","device":"openaps:\/\/samsung SM-S901B","pump":{"battery":{"percent":75},"status":{"status":"normal","timestamp":"2023-01-14T22:51:23.747Z"},"extended":{"Version":"3.1.0.3-dev-g-AIMI-7dc80c1206-2023.01.13","LastBolus":"14\/01\/2023 22:51","LastBolusAmount":0.05,"TempBasalAbsoluteRate":0.42,"TempBasalStart":"14\/01\/2023 22:51","TempBasalRemaining":10,"BaseBasalRate":0.3,"ActiveProfile":"aimi_Fiasp_20230114"},"reservoir":64,"clock":"2023-01-14T22:55:44.432Z"},"openaps":{"suggested":{"reason":"undefined. force basal because you receive 2 time max smb size : 10 minutes0.14999999999999997, 10m@0.42 Force Basal AIMI","temp":"absolute","duration":30,"rate":0.8999999999999999,"timestamp":"2023-01-14T22:55:44.429Z"},"iob":{"iob":0.284,"basaliob":0.107,"activity":0.0019,"time":"2023-01-14T22:55:44.429Z"}},"uploaderBattery":28,"configuration":{}} 1933/1934
22:55:52.812 [RxCachedThreadScheduler-49] D/NSCLIENT: [NSClientPlugin$onStart$9.accept():127]: QUEUE Resend ended: Ping received

the new TBR was successfully set on the pump:

22:55:53.871 [binder:29236_F] D/PUMP: [TemporaryBasalStorageImpl.findTemporaryBasal():34]: Using & removing temporary basal info: TemporaryBasal(timestamp=1673736950485, duration=1800000, rate=300.0, isAbsolute=false, type=NORMAL, id=0, pumpId=0, pumpType=USER, pumpSerial=)
22:55:53.874 [RxCachedThreadScheduler-440] D/DATABASE: [CompatDBHelper$dbChangeDisposable$2.accept():79]: Firing EventTempBasalChange 1673736949000
22:55:53.874 [binder:29236_F] D/DATABASE: [PumpSyncImplementation.syncTemporaryBasalWithPumpId():325]: Inserted TemporaryBasal TemporaryBasal(id=1575, version=0, dateCreated=1673736953872, isValid=true, referenceId=null, interfaceIDs_backing=InterfaceIDs(nightscoutSystemId=null, nightscoutId=null, pumpType=DANA_RS, pumpSerial=, temporaryId=null, pumpId=1673736949000, startId=null, endId=null), timestamp=1673736949000, utcOffset=0, type=NORMAL, isAbsolute=false, rate=300.0, duration=900000)
22:55:53.875 [binder:29236_F] D/PUMPCOMM: [DanaRSPacketAPSHistoryEvents.processMessage():147]: [1673736949000] **NEW** EVENT TEMP_START (1) 14/01/2023 22:55 (1673736949000) Ratio: 300% Duration: 15min

Thanks.

[MilosKozak]

send screenshot of Treatments - TBR from both master and aapsclient

[Foxy7]

send screenshot of Treatments - TBR from both master and aapsclient

These are from my daughters Master version. is this what you mean?

thanks.

[MilosKozak]

data seems to be sent properly. compare tab with TBRs on both phones if there are differences

[Foxy7]

data seems to be sent properly. compare tab with TBRs on both phones if there are differences

Hi @MilosKozak

This isn't correct so I've obviously explained this poorly just to be clear TBRs are not being sent to nightscout for my wife's phone running Dev, but did previously when she was using Master.

e.g. my wife's NS view:

my kids (Master AAPS):

The key difference that I can see is that Dev is not creating these messages, e.g. from my kid's phone running Master i see, but there is no equivalent output on my wife's Dev phone.

my wife's Dev phone correctly initiates the TBRs on the pump:

22:55:44.399 [DefaultDispatcher-worker-5] D/APS: [DetermineBasalAdapterAIMIJS.invoke():95]: Current temp:   {"temp":"absolute","duration":10,"rate":0.42,"minutesrunning":5}

But the version id of the NS log line isn't growing and stuck at 1 and the timestamp is stuck at the go live time of when I installed Dev on her phone on the morning of Sunday 8th Jan:

22:52:07.054 [NSClientServiceHandler] I/NSCLIENT: [DataSyncSelectorImplementation.processChangedTemporaryBasals():510]: Loading TemporaryBasal data Start: 0 TemporaryBasal(id=1, version=1, dateCreated=1673168230344

[MilosKozak]

post here full log from master phone

[MilosKozak]

other solution could be reset database on phone

[Foxy7]

other solution could be reset database on phone

i've just tried this. will feedback results.

[Foxy7]

@MilosKozak Thanks, resetting the database on the phone, via the Maintenance menu/ "Reset Databases" button did the trick.

After 20 mins of new BGs the loop started again and TBRs are now sent to NS.