medic/cht-gateway

SMSs are stuck in PENDING state after being successfully sent

dianabarsan opened this issue · 10 comments

Device(s) tested

key value(s)
medic-gateway version master
device make LG
device model Nexus 5x - Android 8.1
can the problem be recreated on this device? yes

Observed behaviour

All SMSs that Gateway sends are stuck in "PENDING" status after being sent successfully.

Expected behaviour

SMSs should change the status to SENT or DELIVERED after being successfully send and/or delivered to the target.

Steps to recreate

Have Gateway send an SMS. Observe the SMS is received by the target. Gateway reports SMS as "PENDING".

relevant logs:

D MedicGateway: medic.gateway.alert.Db :: getWoMessages() :: item fetch count: 1
I MedicGateway: Sending 1 SMSs...
D MedicGateway: medic.gateway.alert.SmsSender :: sendUnsentSmses() :: attempting to send WoMessage@2586ba7d-8857-4713-839f-8843ce0b3f09-UNSENT
I MedicGateway: sendSms() :: [***********] 'a message'
D MedicGateway: medic.gateway.alert.Db :: updateStatus() :: WoMessage@2586ba7d-8857-4713-839f-8843ce0b3f09-UNSENT :: UNSENT -> PENDING (null)
D MmsService: getAutoPersisting
W BroadcastQueue: Background execution not allowed: receiving Intent { act=medic.gateway.alert.SENDING_REPORT flg=0x10 (has extras) } to medic.gateway.alert.generic/medic.gateway.alert.IntentProcessor
W BroadcastQueue: Background execution not allowed: receiving Intent { act=medic.gateway.alert.DELIVERY_REPORT flg=0x10 (has extras) } to medic.gateway.alert.generic/medic.gateway.alert.IntentProcessor
D WificondControl: Scan result ready event
D MedicGateway: medic.gateway.alert.Db :: getWtMessages() :: item fetch count: 0
MedicGateway: medic.gateway.alert.Db :: getWoMessageStatusUpdates() :: item fetch count: 1
D MedicGateway: medic.gateway.alert.SettingsStore :: loading for context: medic.gateway.alert.WakefulService@9e25ab3
D MedicGateway: medic.gateway.alert.Settings :: Settings() webappUrl=https://gateway:****@7715c5ab.eu.ngrok.io/api/sms

The important bit being:

W BroadcastQueue: Background execution not allowed: receiving Intent { act=medic.gateway.alert.SENDING_REPORT flg=0x10 (has extras) } to medic.gateway.alert.generic/medic.gateway.alert.IntentProcessor
W BroadcastQueue: Background execution not allowed: receiving Intent { act=medic.gateway.alert.DELIVERY_REPORT flg=0x10 (has extras) } to medic.gateway.alert.generic/medic.gateway.alert.IntentProcessor

I tried lowering the compileSdkVersion and targetSdkVersion and buildToolsVersion to 28. No change when tested.

Just tested on another device where the SMSs do get the correct DELIVERED state:

key value(s)
medic-gateway version master
device make HTC
device model ONE - Android 5
can the problem be recreated on this device? yes, when sending multiple. no when sending one.
I/MedicGateway(14790): Sending 1 SMSs...
D/MedicGateway(14790): medic.gateway.alert.SettingsStore :: loading for context: medic.gateway.alert.MessageListsActivity@d584864
D/MedicGateway(14790): medic.gateway.alert.Settings :: Settings() webappUrl=https://gateway:****@a03a65d2.eu.ngrok.io/api/sms
D/MedicGateway(14790): medic.gateway.alert.SettingsStore :: loading for context: medic.gateway.alert.MessageListsActivity@d584864
D/MedicGateway(14790): medic.gateway.alert.Settings :: Settings() webappUrl=https://gateway:****@a03a65d2.eu.ngrok.io/api/sms
D/MedicGateway(14790): medic.gateway.alert.SmsSender :: sendUnsentSmses() :: attempting to send WoMessage@2e178df1-359a-48da-9399-95501d09ea17-UNSENT
I/MedicGateway(14790): sendSms() :: [*******] 'ing rest'
D/MedicGateway(14790): medic.gateway.alert.Db :: updateStatus() :: WoMessage@2e178df1-359a-48da-9399-95501d09ea17-UNSENT :: UNSENT -> PENDING (null)
I/MedicGateway(14790): IntentProcessor.onReceive() :: medic.gateway.alert.SENDING_REPORT
I/MedicGateway(14790): Received sending report for message 2e178df1-359a-48da-9399-95501d09ea17 part -1.
D/MedicGateway(14790): medic.gateway.alert.Db :: getWoMessages() :: item fetch count: 1
D/MedicGateway(14790): medic.gateway.alert.Db :: updateStatus() :: WoMessage@2e178df1-359a-48da-9399-95501d09ea17-PENDING :: PENDING -> SENT (null)
I/MedicGateway(14790): IntentProcessor.onReceive() :: medic.gateway.alert.DELIVERY_REPORT
I/MedicGateway(14790): Received delivery report for message 2e178df1-359a-48da-9399-95501d09ea17 part -1.
D/MedicGateway(14790): medic.gateway.alert.Db :: getWoMessages() :: item fetch count: 1
I/MedicGateway(14790): Delivery status: 0x0
D/MedicGateway(14790): medic.gateway.alert.Db :: updateStatus() :: WoMessage@2e178df1-359a-48da-9399-95501d09ea17-SENT :: null -> DELIVERED (null)

I am seeing the same behavior, though, of delivered that SMSs have PENDING statuses when the gateway sends many messages in quick succession. Retrying an individual one does get it the correct status along with sending it again.

on 137_loop_gateway_forwarding
gateway-highlight

on master
gateway2-highlight

This is happening in Samsung A50 and Infinix Hot 8 devices when using v1.7.4. Messages' status never changes to 'Delivered' or 'Sent'.

v1.5.0 apk shared by @henokgetachew here does not have this problem.

Deferring this to 3.10.0 so we can get 3.9.0 out as soon as possible - please contact me if you consider this more urgent.

The workaround as I understand it is to use an older android or an older apk.

This can be developed and released separately to the rest of cht-core.

Moved to 3.11.0 to align with other gateway work.

Research:
Android Oreo (8+) added restrictions to background process to optimise memory usage. Must intents should be explicit.

In this repository means:

  1. Remove the custom intent actions from the manifest, since they aren't going to be implicit anymore.
  2. Create the Pending Intent and specify the context where it's associated to..
  3. Set the custom action type (from # 1) in the Pending Intent object.

More info here:
Broadcast limitations
Background optimizations
Possible fix
https://commonsware.com/blog/2017/04/11/android-o-implicit-broadcast-ban.html

Research:
Regarding the second issue: Where sending multiple SMS on PENDING status, only one gets updated to SENT.

It could be because we are creating one Pending Intent's broadcast per SMS, but each has the same value for requestCode, overriding the broadcast. The requestCode and the intent are used later to identify the fired broadcast with its associated SMS.
The requestCode is type integer, which limit our capacity for assigning unique values without going too complex. One approach is to use the SMS index from the List, then it'll process 1 list at the time or use the message's hashCode.

@latin-panda We have tested this using the branch and built to my android 11 device. Seeing the messages go from UNSENT -> PENDING ->SENT. The text then sends to my phone.

The struggle we have is that none of QA's have a less than android 8 phone with service and I feel we should probably involve the tech leads to use a "beta" build of the gateway app to see if any issues are found with a prod instance.

Awesome, thanks @newtewt ! I support your idea of involving the tech leads to use the "beta", the Gateway is tricky to test with so many differences between phones and environments :)

I believe this is ready to be merged after our group session we had for testing. Any objections @brad1905 @ngaruko ?

Agreed, no objections