817474 - B2G MMS: handleNotificationIndication()->sendMmsRequest() cannot get the expected HTTP response.

Status: RESOLVED FIXED

(Firefox OS Graveyard :: General, defect)

Description

[Gene Lian (I already quit Mozilla)]

+++ This bug was initially created as a clone of Bug #816827 +++

STR:
====================
  0. Please reproduce this after bug 777251 landed.
  1. Turn on the DEBUG in the MmsService.js.
  2. Rebuild and reflash the Gecko.
  3. Turn on the 3G network.
  4. Use another phone to send an MMS message to this one.
  5. The following log shows the unexpected behaviour: it just hangs there without receiving the correct HTTP response.

UNEXPECTED LOG:
====================
I/Gecko   (  105): -@- MmsService: updateMMSProxyInfo: {"host":"10.1.1.1","port":8080,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}
I/Gecko   (  105): -@- MmsService: parseStreamAndDispatch: msg = {"headers":{"x-mms-message-type":130,"x-mms-transaction-id":"-xW8UMYSGwGXagAAkGun8IgPAAAAAAAA","x-mms-mms-version":16,"from":{"address":"1","type":"alphanum"},"subject":"test","x-mms-message-class":"personal","x-mms-message-size":136,"x-mms-expiry":43223,"x-mms-content-location":{"uri":"http://mms.emome.net:8002/-xW8UMYSGwGXagAAkGun8IgPAAAAAAAA"}},"type":130}
I/Gecko   (  105): -@- MmsService: Register proxy filter
I/Gecko   (  105): -@- MmsService: applyFilter: MMSC is matched: {"MMSC":"http://mms.emome.net:8002","MMSProxyInfo":{"host":"10.1.1.1","port":8080,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}}

NOTE:
====================
You can avoid that by doing the following steps:

  1. Settings -> Cellular & Data -> APN settings
  2. Choose the network that supports MMS.
  3. Reboot the phone (you have to do this; otherwise, we would get the same issue).
  4. Send the MMS message again to this phone by another one.
  5. Now you can get an HTTP response as shown as the following log.

EXPECTED LOG:
====================
I/Gecko   (  105): -@- MmsService: updateMMSProxyInfo: {"host":"10.1.1.1","port":8080,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}
I/Gecko   (  105): -@- MmsService: parseStreamAndDispatch: msg = {"headers":{"x-mms-message-type":130,"x-mms-transaction-id":"7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA","x-mms-mms-version":16,"from":{"address":"1","type":"alphanum"},"subject":"test","x-mms-message-class":"personal","x-mms-message-size":136,"x-mms-expiry":43224,"x-mms-content-location":{"uri":"http://mms.emome.net:8002/7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA"}},"type":130}
I/Gecko   (  105): -@- MmsService: Register proxy filter
I/Gecko   (  105): -@- MmsService: applyFilter: MMSC is matched: {"MMSC":"http://mms.emome.net:8002","MMSProxyInfo":{"host":"10.1.1.1","port":8080,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}}
I/Gecko   (  105): -@- MmsService: xhr success, response headers: Content-Encoding: gzip
I/Gecko   (  105): Content-Type: application/vnd.wap.mms-message
I/Gecko   (  105): -@- MmsService: Unregister proxy filter
I/Gecko   (  105): -@- MmsService: parseStreamAndDispatch: msg = {"headers":{"x-mms-message-type":132,"x-mms-transaction-id":"7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA","x-mms-mms-version":16,"from":{"address":"[phone]","type":"PLMN"},"subject":"test","x-mms-read-report":false,"x-mms-message-class":"personal","x-mms-priority":129,"message-id":"7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA","date":"2012-12-03T03:26:36.000Z","x-mms-delivery-report":true,"content-type":{"media":"application/vnd.wap.multipart.related","params":{"type":"application/smil","start":"<0000>"}}},"type":132,"parts":[{"index":0,"headers":{"content-type":{"media":"text/plain","params":{"charset":{"charset":"utf-8"}}},"content-length":4,"content-location":"0"},"content":{"0":116,"1":101,"2":115,"3":116}}]}
I/Gecko   (  105): -@- MmsService: saveMessageContent: /data/b2g/mozilla/8w15muby.default/mms/7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA/0, saved: true
I/Gecko   (  105): -@- MmsService: sendNotificationResponse: tid = 7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA, status = 129, reportAllowed = true
I/Gecko   (  105): -@- MmsService: Register proxy filter
I/Gecko   (  105): -@- MmsService: applyFilter: MMSC is matched: {"MMSC":"http://mms.emome.net:8002","MMSProxyInfo":{"host":"10.1.1.1","port":8080,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}}
I/Gecko   (  105): -@- MmsService: xhr success, response headers: Content-Length: 0
I/Gecko   (  105): -@- MmsService: Unregister proxy filter
I/Gecko   (  105): -@- MmsService: parseStreamAndDispatch: msg = {"headers":{"x-mms-message-type":134,"x-mms-mms-version":16,"message-id":"7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA","to":{"address":"[phone]","type":"PLMN"},"date":"2012-12-03T03:26:40.000Z","x-mms-status":129},"type":134}
I/Gecko   (  105): -@- MmsService: handleDeliveryIndication: got delivery report for 7Bu8UMYSGwGXagAAkGun8IsPAAAAAAAA

Comment 1

[Gene Lian (I already quit Mozilla)]

Attachment: Part 1, Code Clean-Up!

Let's do some clean-up first, where I think s/MMS/mms sounds more consistent in our MmsService.js context.

Comment 2

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network

Hi Vicamo,

With this patch, the users don't need to manually choose the MMS network (like emome) to receive/send MMS, which should be the general behaviour for most of the mobiles in the field.

To do so, we will try to connect to the MMS network whenever attempting to send the MMS HTTP requests. If the MMS network is not yet connected, temporally buffer the HTTP request and resend it later after the MMS network is available.

Please let me know if you have any other suggestions.

Comment 3

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V2

Hi Vicamo,

Addressing the issues we're discussing about in person. The logic is now complicated. Glad to discuss with you in person again to explain everything I've done. Thanks!

Comment 4

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V2.1

Just fixed a typo. Sorry for the noise!

Comment 5

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V2.2

Comment 6

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V2.3

Comment 7

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V2.4

After some thoughts, I'm still hoping to add back the check of .isClearingMmsRequestQueue for safety, because we'd never known if our clients would wrongly use the callback in the future (that is, to call .sendMmsRequest() in the callback).

Comment 8

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

Comment on attachment 691704 [details] [diff] [review]
Part 2, sendMmsRequest() through MMS network, V2.4

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

Thank you :) But maybe we need some more discuss tomorrow?

::: dom/mms/src/ril/MmsService.js
@@ +53,5 @@
>    Cu.import("resource://gre/modules/MmsPduHelper.jsm", MMS);
>    return MMS;
>  });
>  
> +XPCOMUtils.defineLazyGetter(this, "gril", function () {

'gRIL' would be much more clear to reflect it's a global reference for RadioInterfaceLayer.

@@ +125,5 @@
>  
> +  // A queue to buffer the MMS HTTP requests when the MMS network
> +  // is not yet connected. The buffered requests will be cleared
> +  // if the MMS network fails to be connected within a timer.
> +  mmsRequestQueue: [],  

trailing white spaces

@@ +127,5 @@
> +  // is not yet connected. The buffered requests will be cleared
> +  // if the MMS network fails to be connected within a timer.
> +  mmsRequestQueue: [],  
> +  timerToClearQueue: Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer),
> +  isClearingMmsRequestQueue: false,

per previous discuss, the caller shall handle xhr status 0 as connection error and stop further transmission.

@@ +158,2 @@
>     */
> +  setupMmsNetwork: function setupMmsNetwork(mmsRequest) {

'acquireMmsConnection' might be a better name because you call this function several times. Same applies to 'deactivateMmsNetwork', which might better be 'releaseMmsConnection'.

@@ +158,5 @@
>     */
> +  setupMmsNetwork: function setupMmsNetwork(mmsRequest) {
> +    // If we're in the process of clearing the MMS request queue,
> +    // we shouldn't allow any attempts of MMS network setups.
> +    if (this.isClearingMmsRequestQueue) {

ditto

@@ +180,5 @@
> +      // MMS network fails to be connected within a time period.
> +      this.timerToClearQueue.initWithCallback(function timerToClearQueueCb() {
> +        debug("timerToClearQueueCb: clear the buffered MMS requests due to " +
> +              "the timeout: number: " + this.mmsRequestQueue.length);
> +        this.isClearingMmsRequestQueue = true;

ditto

@@ +235,5 @@
> +                      istream: istream,
> +                      callback: callback}
> +    debug("sendMmsRequest: " + JSON.stringify(mmsRequest));
> +    // Setup the MMS network first. Don't send the request until connected.
> +    if (!this.setupMmsNetwork(mmsRequest)) {

You should have:

  if (!this.mmsNetworkConnected) {
    let mmsRequest = {...}
    this.setupMmsNetwork(mmsRequest(mmsRequest);
    return;
  }

, so that you only create a mmsRequest when needed.

@@ +417,2 @@
>          callback(MMS.MMS_PDU_RESPONSE_ERROR_UNSUPPORTED_MESSAGE, null);
> +        return;

You don't need it for now.

@@ +594,2 @@
>          callback.call(this, MMS.MMS_PDU_STATUS_UNRECOGNISED, null);
> +        return;

ditto

@@ +705,5 @@
>          this.mmsProxySettings.forEach(function(name) {
>            Services.prefs.removeObserver(name, this);
>          }, this);
> +        this.mmsRequestQueue = null;
> +        this.timerToClearQueue.cancel();

Maybe we should invoke all callbacks with error status instead of clearing them all.

Comment 9

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V3

Not yet tested but should be go to go. I'll test everything when back to the office on Monday morning. Please go ahead to review it if you're available on the weekend. Thanks for the review! ;)

Comment 10

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

Comment on attachment 692316 [details] [diff] [review]
Part 2, sendMmsRequest() through MMS network, V3

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

::: dom/mms/src/ril/mms_consts.js
@@ +99,5 @@
>  
>  // Allow this file to be imported via Components.utils.import().
>  this.EXPORTED_SYMBOLS = ALL_CONST_SYMBOLS;
>  
> +this.IS_MMS_PDU_ERROR_TRANSIENT_TYPE = function(status) {

This file is for constants, and no functions are defined here so far. Please move it into MmsService and rename to something like 'isTransientError'.

Comment 11

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V3.1

Everything is working well. Please go ahead to review when you have a chance. Thanks!

Comment 12

[Gene Lian (I already quit Mozilla)]

Attachment: Part 2, sendMmsRequest() through MMS network, V3.2

We were uploading new stuff at the same time. Sorry for confusing you!

Comment 13

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

Comment on attachment 692864 [details] [diff] [review]
Part 2, sendMmsRequest() through MMS network, V3.2

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

Thank you! We'll need more polishes for transaction handling, but for now, let's just move on. ;)

Comment 14

[Gene Lian (I already quit Mozilla)]

(In reply to Vicamo Yang [:vicamo][:vyang] from comment #13)
> Thank you! We'll need more polishes for transaction handling, but for now,
> let's just move on. ;)

Glad and interested in taking this task in the future! :)

Comment 15

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

https://hg.mozilla.org/integration/mozilla-inbound/rev/408694ed2d3e
https://hg.mozilla.org/integration/mozilla-inbound/rev/ba26dc1c6267

Comment 16

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/408694ed2d3e
https://hg.mozilla.org/mozilla-central/rev/ba26dc1c6267

Comment 18

[Gene Lian (I already quit Mozilla)]

This bug relates to MMS features and needs to be tagged as leo+ so that we can uplift it into the b2g-18 branch.

Comment 19

[Dylan Oliver [:doliver]]

Leo triage: leo+ for MMS blockers

Comment 20

[Chia-hung Tai [:ctai :ctai_mozilla :cht]]

Attachment: b2g18-007-bug-817474-part1-fix

Comment 21

[Chia-hung Tai [:ctai :ctai_mozilla :cht]]

Attachment: [b2g18-007]-bug-817474-part1-fix

Comment 22

[Chia-hung Tai [:ctai :ctai_mozilla :cht]]

Attachment: [b2g18]-007-bug-817474-part2-fix

Comment 23

[Gene Lian (I already quit Mozilla)]

https://hg.mozilla.org/releases/mozilla-b2g18/rev/f1a2d8beb234
https://hg.mozilla.org/releases/mozilla-b2g18/rev/77e7301885a2

Comment 24

[Ryan VanderMeulen [:RyanVM]]

The entire set of clian's pushes was backed out for multiple reasons.
https://tbpl.mozilla.org/?tree=Mozilla-B2g18&rev=a0b06192f882

1.) The tree rules are clear that you are not to land on top of bustage. At the time you pushed, both B2G Mn and B2G xpcshell had bustage from prior commits that hadn't been backed out yet.
2.) The tree rules are also clear that you are to watch your pushes for any bustage and handle them accordingly. mozilla-inbound is the ONLY tree where this rule does not apply.
3.) Even after the earlier bustage was backed out, something in one of your many pushes was causing further B2G Mn failures as shown in the log below.
https://tbpl.mozilla.org/php/getParsedLog.php?id=20424173&tree=Mozilla-B2g18
4.) This isn't cause for backout by itself, but it is also strongly preferred to not push each commit individually as our build and testing resources are limited and doing so stretches them even thinner. Please limit your number of pushes as much as possible unless you have good reason for keeping them separate.

Comment 25

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

https://hg.mozilla.org/releases/mozilla-b2g18/rev/99680a32f297