[EOPATCH2] Problem delivering bolus [Master][3.2.0.3]

Start with the logged EopatchPumpPlugin.getPumpStatus(), PatchStateManager, TaskQueue, and ReadBolusFinishTimeTask entry points. Trace the bolus status and the plaintext-packet error across the recorded sequence, then verify that a delivered bolus finishes correctly, active insulin is recorded, and the pump is not reported as unreachable.

Events are recorded: "Pump not reachable".

Bolus starts to be delivered, but does not finish correctly. Active insulin does not appear, but bolus is delivered.

The problem has occurred with several patches. Today it happened with two.

The following error messages are logged:

13:17:11.113 [RxCachedThreadScheduler-27] D/PUMPCOMM: [TaskQueue.publishTicket():53]: publishTicket() Task #:0 is assigned func:UPDATE_CONNECTION
13:17:11.114 [RxCachedThreadScheduler-27] D/PUMPCOMM: [TaskQueue.lambda$isReady$4$info-nightscout-androidaps-plugins-pump-eopatch-ble-task-TaskQueue():40]: Task #:0 started func:UPDATE_CONNECTION
13:17:11.245 [main] D/CORE: [DummyService.onCreate():43]: Starting DummyService with ID 4711 notification Notification(channel=AndroidAPS-Ongoing shortcut=null contentView=null vibrate=null sound=null defaults=0x0 flags=0xa color=0x00000000 category=status vis=PRIVATE semFlags=0x0 semPriority=0 semMissedCount=0)
13:17:11.295 [main] D/CORE: [DummyService.onStartCommand():69]: Starting DummyService with ID 4711 notification Notification(channel=AndroidAPS-Ongoing shortcut=null contentView=null vibrate=null sound=null defaults=0x0 flags=0xa color=0x00000000 category=status vis=PRIVATE semFlags=0x0 semPriority=0 semMissedCount=0)
13:17:11.364 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.publishTicket():53]: publishTicket() Task #:1 is assigned func:READ_BOLUS_FINISH_TIME
13:17:11.366 [main] D/PUMP: [PatchStateManager.lambda$updatePatchState$2$info-nightscout-androidaps-plugins-pump-eopatch-ble-PatchStateManager():46]: PatchState GlobalTime:2024/02/09 13:17:11 --> D8 15 0A 10 A0 02 00 00 00 04 B0 3C [NowBolus] RegAct:On Done:On [NormalBasal] Reg:On Act:On Paused: remainedInsulin:60 remainedPumpCycle:1200(60.0) battery:3,05V
13:17:11.534 [Thread-11] D/PUMPQUEUE: [QueueThread.run():123]: connection time 4s
13:17:11.535 [Thread-11] D/PUMPQUEUE: [QueueThread.run():129]: performing READSTATUS Controlador de bomba cambiado
13:17:11.538 [Thread-11] D/CORE: [EopatchPumpPlugin.getPumpStatus():170]: Acknowledged AAPS getPumpStatus request
13:17:11.539 [Thread-11] D/PUMPCOMM: [TaskQueue.publishTicket():53]: publishTicket() Task #:2 is assigned func:UPDATE_CONNECTION
13:17:11.545 [Thread-11] D/PUMPQUEUE: [CommandReadStatus.execute():25]: CommandReadStatus executed. Reason: Controlador de bomba cambiado
13:17:11.621 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.done():73]: done() Task #:0 completed func:UPDATE_CONNECTION task remaining:2
13:17:11.622 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.lambda$isReady$4$info-nightscout-androidaps-plugins-pump-eopatch-ble-task-TaskQueue():40]: Task #:1 started func:READ_BOLUS_FINISH_TIME
13:17:11.627 [main] D/PUMP: [PatchStateManager.lambda$updatePatchState$2$info-nightscout-androidaps-plugins-pump-eopatch-ble-PatchStateManager():46]: PatchState GlobalTime:2024/02/09 13:17:11 --> 58 15 0A 10 A0 02 00 00 00 04 B0 3C [NowBolus] RegAct:On Done:On [NormalBasal] Reg:On Act:On Paused: remainedInsulin:60 remainedPumpCycle:1200(60.0) battery:3,05V
13:17:11.651 [Thread-11] D/PUMPQUEUE: [QueueThread.run():156]: waiting for disconnect
13:17:12.046 [RxCachedThreadScheduler-42] D/NSCLIENT: [NSClientV3Plugin$onStart$9.accept():241]: ● DONE PROCESSING BG
13:17:12.046 [DefaultDispatcher-worker-4] D/WORKER: [LoggingWorker$doWork$2.invokeSuspend():27]: Worker result SUCCESS for class app.aaps.plugins.sync.nsclientV3.workers.LoadBgWorker
13:17:12.087 [RxCachedThreadScheduler-42] D/NSCLIENT: [NSClientV3Plugin$onStart$9.accept():241]: ◄ RCV TR END No new data from 2/2/24 09:21:27
13:17:12.646 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.done():73]: done() Task #:1 completed func:READ_BOLUS_FINISH_TIME task remaining:1
13:17:12.649 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.lambda$isReady$4$info-nightscout-androidaps-plugins-pump-eopatch-ble-task-TaskQueue():40]: Task #:2 started func:UPDATE_CONNECTION
13:17:12.650 [RxSingleScheduler-1] E/PUMPCOMM: [ReadBolusFinishTimeTask.lambda$read$1$info-nightscout-androidaps-plugins-pump-eopatch-ble-task-ReadBolusFinishTimeTask():32]: Error in sending plaintext packets in encrypted communication
13:17:12.651 [RxSingleScheduler-1] W/CORE: [MainApp$setRxErrorHandler$1.accept():193]: Undeliverable exception received, not sure what to do
13:17:12.654 [Thread-11] D/PUMPQUEUE: [QueueThread.run():156]: waiting for disconnect
13:17:12.882 [RxSingleScheduler-1] D/PUMPCOMM: [TaskQueue.done():73]: done() Task #:2 completed func:UPDATE_CONNECTION task remaining:0
13:17:12.883 [main] D/PUMP: [PatchStateManager.lambda$updatePatchS
tate$2$info-nightscout-androidaps-plugins-pump-eopatch-ble-PatchStateManager():46]: PatchState GlobalTime:2024/02/09 13:17:12 --> 58 15 0A 10 A0 02 00 00 00 04 B0 3C [NowBolus] RegAct:On Done:On [NormalBasal] Reg:On Act:On Paused: remainedInsulin:60 remainedPumpCycle:1200(60.0) battery:3,05V
13:17:13.657 [Thread-11] D/PUMPQUEUE: [QueueThread.run():156]: waiting for disconnect
13:17:14.659 [Thread-11] D/PUMPQUEUE: [QueueThread.run():156]: waiting for disconnect
13:17:15.664 [Thread-11] D/PUMPQUEUE: [QueueThread.run():156]: waiting for disconnect
13:17:16.665 [Thread-11] D/PUMPQUEUE: [QueueThread.run():148]: queue empty. disconnect
13:17:16.667 [Thread-11] D/PUMP: [EopatchPumpPlugin.disconnect():159]: EOPatch disconnect - reason:Queue empty
13:17:16.667 [Thread-11] D/PUMPQUEUE: [QueueThread.run():152]: disconnected
13:17:16.669 [Thread-11] D/PUMPQUEUE: [QueueThread.run():163]: thread end

AndroidAPS_LOG_1707481059184.log.zip
AndroidAPS_LOG_1707488434789.log.zip