Closed Bug 1155022 Opened 5 years ago Closed 5 years ago

[RIL] Intermittent script timed out in test_outgoing_radio_off.js due to emulator command, `gsm cancel`, doesn't trigger UNSOLICITED_RESPONSE_CALL_STATE_CHANGED.

Categories

(Firefox OS Graveyard :: Emulator, defect)

x86_64
Linux
defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: edgar, Assigned: edgar)

References

Details

Attachments

(2 files)

I though the intermittent failure in test_outgoing_radio_off.js is caused by the same reason as bug 1152272. But after applying the solution of bug 1152272, intermittent failure still show in try: https://treeherder.mozilla.org/logviewer.html#?job_id=6575653&repo=try.

I capture the log from radio buffer, and found something interesting,
- Normal case (https://treeherder.mozilla.org/logviewer.html#?job_id=6579106&repo=try):
> 04-15 15:46:38.262    44    44 I Gecko   : 1429112798268	Marionette	DEBUG	conn108 emulator <- ({"emulator_cmd":"gsm cancel 112","id":3})
> 04-15 15:46:38.312    44   142 I Gecko   : RIL Worker: [0] New outgoing parcel of type 28
> 04-15 15:46:38.322    44   142 I Gecko   : RIL Worker: Outgoing parcel: 0,0,0,64,28,0,0,0,139,5,0,0,178,0,0,0,198,111,0,0,8,0,0,0,51,0,102,0,48,0,48,0,55,0,102,0,50,0,48,0,0,0,0,0,7,0,0,0,4,0,0,0,24,0,0,0,255,255,255,255,255,255,255,255,255,255,255,255
> 04-15 15:46:38.372    38    83 D AT      : AT< NO CARRIER
> 04-15 15:46:38.392    38    79 D RIL     : onRequest: SIM_IO
> 04-15 15:46:38.392    38    79 D AT      : AT> AT+CRSM=178,28614,7,4,24
> 04-15 15:46:38.392    38    83 D AT      : AT< +CRSM: 144,0,00d1dd0000fffe07ffffffffffffffffffffffffffffffff
> 04-15 15:46:38.392    38    83 D AT      : AT< OK

- Failure case (https://treeherder.mozilla.org/logviewer.html#?job_id=6575653&repo=try):
> 04-15 13:10:05.886    44    44 I Gecko   : 1429103405894	Marionette	DEBUG	conn108 emulator <- ({"emulator_cmd":"gsm cancel 112","id":3})
> 04-15 13:10:05.907    44   141 I Gecko   : RIL Worker: [0] New outgoing parcel of type 28
> 04-15 13:10:05.907    44   141 I Gecko   : RIL Worker: Outgoing parcel: 0,0,0,64,28,0,0,0,139,5,0,0,178,0,0,0,198,111,0,0,8,0,0,0,51,0,102,0,48,0,48,0,55,0,102,0,50,0,48,0,0,0,0,0,10,0,0,0,4,0,0,0,24,0,0,0,255,255,255,255,255,255,255,255,255,255,255,255
> 04-15 13:10:05.957    38    83 D RIL     : onRequest: SIM_IO
> 04-15 13:10:05.957    38    83 D AT      : AT> AT+CRSM=178,28614,10,4,24
> 04-15 13:10:05.957    38    87 D AT      : AT< NO CARRIER
> 04-15 13:10:05.957    38    87 D AT      : AT< +CRSM: 144,0,ffffffffffffffffffffffffffffffffffffffffffffffff
> 04-15 13:10:05.957    38    87 D AT      : AT< OK

No AT command lost, but the command sequence are different.
Blocks: 1081529
Summary: [RIL] script timed out in test_outgoing_radio_off.js due to emulator command, `gsm cancel`, doesn't trigger UNSOLICITED_RESPONSE_CALL_STATE_CHANGED. → [RIL] Intermittent script timed out in test_outgoing_radio_off.js due to emulator command, `gsm cancel`, doesn't trigger UNSOLICITED_RESPONSE_CALL_STATE_CHANGED.
According to the spec, TS 127.007, 'NO CARRIER` could be: (See Annex E, F and G)
- An unsolicited message to notify remote hangup call.
- A final response for a request.

Rild decide the "NO CARRIER" is an unsolicited message or a final response by checking is there any pending request [1]. 

For the failed case mentioned in comment #0, the AT command sequence is like:
> AT> AT+CRSM=178,28614,10,4,24
> AT< NO CARRIER
> AT< +CRSM: 144,0,ffffffffffffffffffffffffffffffffffffffffffffffff
> AT< OK
The "NO CARRIER" was treated as the final response of "AT+CRSM .." request.

The ideal solution is having some way to ensure the sequence of AT response, but it is not easy to do that. Besides, current qemu doesn't support replying "NO CARRIER" as final response for now actually, we could just let rild always treat "NO CARRIER" as an unsolicited message, which is a much easier way to solve this issue.

[1] https://github.com/EdgarChen/platform_hardware_ril/blob/09b65d623026b7fdaa6be53c53b0e99d8130a134/reference-ril/atchannel.c#L245-L253
Working branch: https://github.com/EdgarChen/platform_hardware_ril/commits/bug_1155022/NO_CARRIER

Try looks good, https://treeherder.mozilla.org/logviewer.html#?job_id=6640616&repo=try, even having same sequence as failure case in comment #0, but it works perfect with the patch.
> 04-16 15:45:54.521 D/AT      (   38): AT> AT+CRSM=178,28613,7,4,24
> 04-16 15:45:54.531 D/AT      (   38): AT< NO CARRIER
> 04-16 15:45:54.531 D/AT      (   38): AT< +CRSM: 144,0,430685d4f29c7e03ffffffffffffffffffffffffffffffff
> 04-16 15:45:54.531 D/AT      (   38): AT< OK
> 04-16 15:45:54.551 I/Gecko   (   44): RIL Worker: [0] Handling parcel as UNSOLICITED_RESPONSE_CALL_STATE_CHANGED
PR for platform_hardware_ril:master
PR for platform_hardware_ril:b2g-ril_v7.
Comment on attachment 8593783 [details] [review]
[platform_hardware_ril:master] PR #50

Hi Hsinyi, may I have your review (Please see comment #1 and comment #2 for more details)? Thank you.
Attachment #8593783 - Flags: review?(htsai)
Attachment #8593784 - Flags: review?(htsai)
See Also: → 1018051
Comment on attachment 8593783 [details] [review]
[platform_hardware_ril:master] PR #50

The explanation is fair enough. Thank you for catching this.
Attachment #8593783 - Flags: review?(htsai) → review+
Attachment #8593784 - Flags: review?(htsai) → review+
Assignee: nobody → echen
You need to log in before you can comment on or make changes to this bug.