1150368 - Mms always can't send out the m-Acknowledge.ind when retrieving a mms in manual mode

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: RIL, defect, P1)

Description

[田旻]

When I retrieve a mms in manual mode, and download it, the pdu "M-Acknowledge.ind" always miss.
Note: You can just send a single piece of mms and make sure you are in manuel mode, then check the tcpdump about this procedure, you wouldn't see the "M-Acknowledge.ind" in it.

But at this time, when you send or receive another mms, or connect the data connection, whichever way used to active the tcp connection is ok, you will see the missing pdu "Ｍ-acknowledge" is back.

Comment 1

[田旻]

Attachment: retrieveMms1.pcap

This is the first tcpdump, which miss the m-Acknowledge. No matter how log I wait, the m-Acknowledge will not send.

Comment 2

[田旻]

Attachment: retrieveMms2.pcap

This is the second tcpdump, when I open the browser and search "www.baidu.com" , which mean the tcp has been connected again, and the m-Acknowledge is back.

Comment 3

[田旻]

Attachment: test123.pcap

This is the third tcpdump which is similar as the second one, but we can see the common between these two: Ｂoth of their Ｍ-acknowledge will send after a disconnect of tcp.  Ｉ think that will be the reason for the missing pdu.

Comment 4

[Vance Chen [:vchen][skype:vance.lucida][[e-mail]]]

Hi Bevis, could you help to check this one? It was reported by one carrier and is now becoming a blocker issue

Thanks

Comment 5

[田旻]

Attachment: logcat20150402_151658.log

Ｔhis is the logcat about the ＭmsＳervice.js, but Ｉ can't find any abnormal during the logcat.

Comment 6

[田旻]

Mozilla Build ID: 20141019000201

Comment 7

[田旻]

Note: Ａctually, there is another bug about PDU "M-NotifyRep.ind" is missing during the retrieve of a mms.
But I think both of these two bugs are about the "POST" of message to mms proxy-reply. They should be the same kind of problems about the disconnection of tcp link during retrieving .

Comment 8

[田旻]

[Blocking Requested - why for this release]:

Comment 9

[田旻]

Dear Bevis,
This block is very urgent, please analysis it as soon as possible.
BRs,
TIAN Min

Comment 10

[田旻]

The most important problem is why a tcp request can't be build when "POST" a pdu to mms proxy-reply.

Comment 11

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to 田旻 from comment #5)
> Created attachment 8587200 [details]
> logcat20150402_151658.log
> 
> Ｔhis is the logcat about the ＭmsＳervice.js, but Ｉ can't find any abnormal
> during the logcat.

Hi,

From the main log, I cannot see the symptom you mentioned about "Ｍ-Acknowledge will send after a disconnect of tcp".
The call flow looks normal to me and the M-Ack was sent immediately after message retreived.
Please see my explanation inline.

I can not reproduce this problem from my side. :(

Is it possible to have the main log with corresponding tcpdump which includes the symptom you mentioned for further analysis?

It will be more helpful to narrow down the problem if you can point out when & where the symptom happens from both main log & tcpdump.

In addition, here is the implementation where M-Acknowledge-ind will be sent after manually retrieved for your reference:
http://mxr.mozilla.org/mozilla-b2g32_v2_0/source/dom/mobilemessage/src/gonk/MmsService.js#2530

--
[MMS Transaction flow in the main log attached in comment 5]
1. The device received a MMS Notification at:
04-02 15:17:09.213 I/Gecko   ( 6805): -@- MmsService: receiveWapPush: msg = {"headers":{"x-mms-message-type":130,"x-mms-transaction-id":"CPMlJI4Kwk+A","x-mms-mms-version":16,"x-mms-content-location":{"uri":"http://10.95.251.141/CPMlJI4Kwk+A"},"x-mms-expiry":259200,"from":{"address":"[phone]","type":"PLMN"},"x-mms-message-class":"personal","x-mms-message-size":2661},"type":130}


2. MmsService setup the MMS data call to send the M-NotifyResp.ind back to MMSC with positive response:
04-02 15:17:09.323 I/Gecko   ( 6805): -@- MmsService: acquire: buffer the MMS request and setup the MMS data call.
04-02 15:17:09.323 D/DATA_CALL_TRACKER( 6805): SetupDataCall :: Initiating data call for apn '3gwap'
04-02 15:17:10.833 I/Gecko   ( 6805): -@- MmsService: sendRequest: register proxy filter to http://mmsc.myuni.com.cn
04-02 15:17:10.833 I/Gecko   ( 6805): -@- MmsService: getProxyInfo: {"host":"10.0.0.172","port":80,"type":"http","flags":1,"resolveFlags":0,"failoverTimeout":1800,"failoverProxy":null,"TRANSPARENT_PROXY_RESOLVES_HOST":1}
04-02 15:17:10.833 I/Gecko   ( 6805): -@- MmsService: applyFilter: MMSC/Content Location is matched ...


3. User manually retrieved the MMS message at:
04-02 15:17:13.383 I/Gecko   ( 6805): -@- MmsService: Retrieving message with ID 9
04-02 15:17:13.753 I/Gecko   ( 6805): -@- MmsService: retrievedMsg = {...}
04-02 15:17:13.823 I/Gecko   ( 6805): -@- MmsService: Broadcasting the MMS system message: sms-received

4. Device send M-Acknowledge.ind back to MMSC with positive response.
04-02 15:17:14.023 I/Gecko   ( 6805): -@- MmsService: sendRequest: register proxy filter to http://mmsc.myuni.com.cn
04-02 15:17:14.033 I/Gecko   ( 6805): -@- MmsService: getProxyInfo: ...
04-02 15:17:14.243 I/Gecko   ( 6805): -@- MmsService: xhr success, response headers: Content-Length: 0

4. Device release the MMS connection after 30-second timeout:
04-02 15:17:44.243 I/Gecko   ( 6805): -@- MmsService: onDisconnectTimerTimeout: deactivate the MMS data call.
04-02 15:17:44.253 D/DATA_CALL_TRACKER( 6805): DeactivateDataCall::aCid=0, aReason=0

Comment 12

[田旻]

Attachment: logcat20150402_181234.log

Dear Bevis,

I can't get any abnormal in logcat both when missing or not missing a pdu.
Ｔhis is the logcat about the missing pdu relative logcat.

On the other hand, we have ask our customer to give their logcat and tcpdump about this bug, I will attach it here when they give us.

BRs,
TIAN Min

Comment 13

[Bevis Tseng[:bevis][:btseng](Exited)]

(In reply to 田旻 from comment #12)
> Created attachment 8587277 [details]
> logcat20150402_181234.log
> 
> Dear Bevis,
> 
> I can't get any abnormal in logcat both when missing or not missing a pdu.
> Ｔhis is the logcat about the missing pdu relative logcat.
Can you help to explain how you verdict "there is PDU missed" according to the logcat you attached?
Even in this log, I can see that the ACK was sent at:
04-02 18:13:06.003 I/Gecko   ( 6805): -@- MmsService: sendRequest: register proxy filter to http://mmsc.myuni.com.cn
with positive response at:
04-02 18:13:06.253 I/Gecko   ( 6805): -@- MmsService: xhr success, response headers: Content-Length: 0
From the logcat, it's quite obvious that transaction is done with HTTP STATUS to 200 OK.
Is there anything wrong in server side instead that cause server not aware of an ACK delivered, even when the client sides got 200 OK from server?
> On the other hand, we have ask our customer to give their logcat and tcpdump
> about this bug, I will attach it here when they give us.
> 
> BRs,
> TIAN Min

Comment 14

[田旻]

(In reply to Bevis Tseng[:bevistseng][:btseng] from comment #13)
> (In reply to 田旻 from comment #12)
> > Created attachment 8587277 [details]
> > logcat20150402_181234.log
> > 
> > Dear Bevis,
> > 
> > I can't get any abnormal in logcat both when missing or not missing a pdu.
> > Ｔhis is the logcat about the missing pdu relative logcat.
> Can you help to explain how you verdict "there is PDU missed" according to
> the logcat you attached?
> Even in this log, I can see that the ACK was sent at:
> 04-02 18:13:06.003 I/Gecko   ( 6805): -@- MmsService: sendRequest: register
> proxy filter to http://mmsc.myuni.com.cn
> with positive response at:
> 04-02 18:13:06.253 I/Gecko   ( 6805): -@- MmsService: xhr success, response
> headers: Content-Length: 0
> From the logcat, it's quite obvious that transaction is done with HTTP
> STATUS to 200 OK.
> Is there anything wrong in server side instead that cause server not aware
> of an ACK delivered, even when the client sides got 200 OK from server?
> > On the other hand, we have ask our customer to give their logcat and tcpdump
> > about this bug, I will attach it here when they give us.
> > 
> > BRs,
> > TIAN Min

I used tcpdump to grap the package about the procedure of retrieving mms.
When I can't see the pdu in the tcpdump package with Wireshark, I think this pdu is missing.

But I find some strange things during a series of test. 
When I used  command "tcpdump -i any -p -vv -s 0  -w /sdcard/filename.pcap" I find the last pdu always miss, but when I use command "tcpdump -i any -p -vv -s 2000 -n -U -w /sdcard/filename.pcap" I can see the last pdu but some other pdu  disappear. Apparently, the parameters is important for the results.  Maybe some test tool related problem  in our side......
I am not sure what kind of test tools our operator customer used, but this bug has been proposed by two different areas about the same thing. Do they make the same mistake about the test tool or do they use the same kind of test tool....
But now, we can only contact CTS to deal with this bug but operators. 
We are still waiting for the feedback of qxdm and logcat or tcpdump from our operator customer about this bug.

BRs,
TIAN Min

Comment 16

[Wesley Huang [:wesley_huang] (EPM) (NI me)]

Hi reporter,
From Bevis' investigation, all behaviors seem working correctly.
Logcat file showed no issue there, while the only unexpected thing is from tcpdump.
We really shouldn't block on this.

Comment 17

[BMO Automation]

Firefox OS is not being worked on