838190 - B2G SMS: Receiving a contact card via SMS blocks receiving any further text messages

Status: RESOLVED FIXED

(Core :: DOM: Device Interfaces, defect)

Description

[Thomas B. Rücker [account mostly dormant]]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:18.0) Gecko/20100101 Firefox/18.0
Build ID: 20130116073211

Steps to reproduce:

1) send text message 'test1' to a FxOS phone
2) send text message containing a vcard to a FxOS phone
3) send text message 'test2' to a FxOS phone
4) optional send messages from more than one phone. 'test3', etc.


Actual results:

Only 'test1' was received. No further text messages were received.


Expected results:

The vcard message should have been received (processing is a different matter).
The 'test2' and followingb should have been received.

Requesting blocking-tev, given the fact that this breaks receiving text messages completely (until either the network discards the message, which can take weeks; or the SIM is inserted into a different phone).

Comment 1

[Thomas B. Rücker [account mostly dormant]]

additional fumbling with the bug options.
Credit: Originally found by KaiRo, not me. I just verified it too.

Comment 2

[Robert Kaiser]

FYI, once you insert the SIM into a different phone, the contact and the other SMS are received there, and then you can put the SIM back into the FxOS phone and it can receive normal SMS again.
That's just not a dance we can expect normal users to do (and given they get no indicator that they received anything, all they notice is that friends call them and ask them why they didn't react to an SMS - as they never received it).

Comment 3

[Robert Kaiser]

Oh, and given that I saw it twice already (on otoro), and Thomas could reproduce (on unagi), this is confirmed and reproducible.

Comment 4

[Vicamo Yang [:vicamo][:vyang]]

Could you help capture RIL debug messages by:

1) adb remount
2) adb pull /system/b2g/defaults/pref/user.js user.js
3) update user.js with adding 'pref("ril.debugging.enabled", true);'
4) adb push user.js /system/b2g/defaults/pref/user.js
5) adb shell reboot
6) adb logcat

Comment 5

[Thomas B. Rücker [account mostly dormant]]

Attachment: Logcat of device receiving 'test1' (vcard and 'test2' were sent too during logcat, but not received on the UI)

Had to insert SIM into different device again to make SMS work.

vyang: Unless the ONRPC is the RIL debug output, then I don't see any? I verified by pulling the file after reboot. the line as specified is there on the device: pref("ril.debugging.enabled", true);

This is an Unagi with a Gaia build from an hour ago.

Comment 6

[Thomas B. Rücker [account mostly dormant]]

All attempts to persuade my Unagi to enable ril.debugging.enabled have failed so far for unknown reasons. (We tried above mentioned user.js; prefs.js in the profile and adding a user.js in the profile)

This will need investigation by someone able to rebuild B2G from scratch with this pref forced. (my build has yet to succeed and I don't have that much time to fix it)

Comment 7

[Vicamo Yang [:vicamo][:vyang]]

Re-nominate to normal, not blocking other application releases.

Comment 8

[Thomas B. Rücker [account mostly dormant]]

I'm now able to rebuild the full B2G for my Unagi.
What is the magic incantation for having having "ril.debugging.enabled true" with --force --whateverittakes --yes-really --yep --with-full-prejudice

Comment 9

[Thomas B. Rücker [account mostly dormant]]

Attachment: Full logcat showing 'test 1' and failed vcard receiving

Seems like the rebuilt from scratch B2G image fixed the problem with enabling ril.debugging.enabled. I now captured a whole boot + the problematic message reception.
Hope that helps.

Comment 10

[Robert Kaiser]

Comment on attachment 711282 [details]
Full logcat showing 'test 1' and failed vcard receiving

>I/Gecko   (  108): RIL Worker: Got new SMS: {"SMSC":"[phone]","mti":0,"udhi":64,"sender":"[phone]","recipient":null,"pid":0,"epid":0,"dcs":4,"mwi":null,"replace":false,"header":{"length":6,"langIndex":0,"langShiftIndex":0,"destinationPort":9204,"originatorPort":0},"body":null,"data":{"0":66,"1":69,"2":71,"3":73,"4":78,"5":58,"6":86,"7":67,"8":65,"9":82,"10":68,"11":13,"12":10,"13":86,"14":69,"15":82,"16":83,"17":73,"18":79,"19":78,"20":58,"21":51,"22":46,"23":48,"24":13,"25":10,"26":78,"27":58,"28":75,"29":117,"30":111,"31":114,"32":105,"33":108,"34":101,"35":104,"36":116,"37":111,"38":59,"39":77,"40":97,"41":114,"42":105,"43":97,"44":59,"45":59,"46":59,"47":13,"48":10,"49":78,"50":73,"51":67,"52":75,"53":78,"54":65,"55":77,"56":69,"57":58,"58":13,"59":10,"60":84,"61":69,"62":76,"63":59,"64":84,"65":89,"66":80,"67":69,"68":61,"69":67,"70":69,"71":76,"72":76,"73":44,"74":86,"75":79,"76":73,"77":67,"78":69,"79":58,"80":43,"81":51,"82":53,"83":56,"84":52,"85":52,"86":51,"87":50,"88":51,"89":56,"90":55,"91":57,"92":51,
>I/Gecko   (  108): -*- RadioInterfaceLayer: Received message from worker: {"SMSC":"[phone]","mti":0,"udhi":64,"sender":"[phone]","recipient":null,"pid":0,"epid":0,"dcs":4,"mwi":null,"replace":false,"header":{"length":6,"langIndex":0,"langShiftIndex":0,"destinationPort":9204,"originatorPort":0},"body":null,"timestamp":1360243124000,"status":null,"scts":null,"dt":null,"encoding":4,"messageClass":"normal","fullData":{"0":66,"1":69,"2":71,"3":73,"4":78,"5":58,"6":86,"7":67,"8":65,"9":82,"10":68,"11":13,"12":10,"13":86,"14":69,"15":82,"16":83,"17":73,"18":79,"19":78,"20":58,"21":51,"22":46,"23":48,"24":13,"25":10,"26":78,"27":58,"28":75,"29":117,"30":111,"31":114,"32":105,"33":108,"34":101,"35":104,"36":116,"37":111,"38":59,"39":77,"40":97,"41":114,"42":105,"43":97,"44":59,"45":59,"46":59,"47":13,"48":10,"49":78,"50":73,"51":67,"52":75,"53":78,"54":65,"55":77,"56":69,"57":58,"58":13,"59":10,"60":84,"61":69,"62":76,"63":59,"64":84,"65":89,"66":80,"67":69,"68":61,"69":67,"70":69,"71":76,"72":76,"73":44,"74":86,"75":79,"76
>I/Gecko   (  108): -*- RadioInterfaceLayer: handleSmsReceived: {"SMSC":"[phone]","mti":0,"udhi":64,"sender":"[phone]","recipient":null,"pid":0,"epid":0,"dcs":4,"mwi":null,"replace":false,"header":{"length":6,"langIndex":0,"langShiftIndex":0,"destinationPort":9204,"originatorPort":0},"body":null,"timestamp":1360243124000,"status":null,"scts":null,"dt":null,"encoding":4,"messageClass":"normal","fullData":{"0":66,"1":69,"2":71,"3":73,"4":78,"5":58,"6":86,"7":67,"8":65,"9":82,"10":68,"11":13,"12":10,"13":86,"14":69,"15":82,"16":83,"17":73,"18":79,"19":78,"20":58,"21":51,"22":46,"23":48,"24":13,"25":10,"26":78,"27":58,"28":75,"29":117,"30":111,"31":114,"32":105,"33":108,"34":101,"35":104,"36":116,"37":111,"38":59,"39":77,"40":97,"41":114,"42":105,"43":97,"44":59,"45":59,"46":59,"47":13,"48":10,"49":78,"50":73,"51":67,"52":75,"53":78,"54":65,"55":77,"56":69,"57":58,"58":13,"59":10,"60":84,"61":69,"62":76,"63":59,"64":84,"65":89,"66":80,"67":69,"68":61,"69":67,"70":69,"71":76,"72":76,"73":44,"74":86,"75":79,"76":73,"77":6


(I don't know anything about details, I'm just observing and guessing.)

For one thing, it looks to me like logcat would be cutting off the long lines here, which might be unfortunate.

That said, I wonder if our code has problems with the fact that those SMS have "body":null there (and all contents are in the "data", actually).

Comment 11

[Vicamo Yang [:vicamo][:vyang]]

(In reply to Robert Kaiser (:[e-mail]) from comment #10)
> Comment on attachment 711282 [details]
> Full logcat showing 'test 1' and failed vcard receiving

Thank you! Root cause found. I'll upload a patch tomorrow. :)

Comment 12

[David Scravaglieri [:scravag]]

Andrew please, as Vicamo is on holiday, could you assign someone on this issue ?

Comment 13

[Vicamo Yang [:vicamo][:vyang]]

Attachment: ensure every received SMS message is acked

try https://tbpl.mozilla.org/?tree=Try&rev=56412a001521

Comment 14

[Gregor Wagner [:gwagner]]

Comment on attachment 713797 [details] [diff] [review]
ensure every received SMS message is acked

Review of attachment 713797 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/system/gonk/RadioInterfaceLayer.js
@@ +594,5 @@
> +            this.worker.postMessage({
> +              rilMessageType: "ackSMS",
> +              result: RIL.PDU_FCS_OK
> +            });
> +          }

Why do you need the try{} here? Just conservative or a real reason?

Comment 15

[Vicamo Yang [:vicamo][:vyang]]

(In reply to Gregor Wagner [:gwagner] from comment #14)
> Why do you need the try{} here? Just conservative or a real
> reason?

Yes, only be conservative. I'll remove it when pushing to inbound. Should solve possible exceptions instead. And, I'm just waiting the retrial of R4 test case before pushing to inbound.

Comment 16

[Vicamo Yang [:vicamo][:vyang]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/9e0279c63245

Comment 17

[Vicamo Yang [:vicamo][:vyang]]

Attachment: ensure every received SMS message is acked : v2

Attach pushed patch. Removed try-finally block.

Comment 18

[:Ms2ger (he/him; ⌚ UTC+1/+2)]

https://hg.mozilla.org/mozilla-central/rev/9e0279c63245

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g18/rev/f770d6dcdb60
https://hg.mozilla.org/releases/mozilla-b2g18_v1_0_1/rev/fe2f3e2bc033