1139835 - [Secure Element] RIL error 16 when trying to open multiple logical channels on Nexus 5L

Status: RESOLVED FIXED

(Firefox OS Graveyard :: RIL, defect)

Description

[Krzysztof Mioduszewski[:tauzen]]

It is not possible to open more than 1 logical channel in the same time on Nexus 5L. Opening second channel results in RIL error code 16, which does not have a error message. Opening multiple channels was possible on Flame 2.1 with QCRIL.

Comment 1

[Krzysztof Mioduszewski[:tauzen]]

Attachment: ril-opening-second-channel-fail.log

Comment 2

[Krzysztof Mioduszewski[:tauzen]]

Attachment: full-opening-second-channel-fail.log

Comment 3

[Edgar Chen [:edgar]]

In ril version 10, error 16 mean "no logical channel available" [1]. Looks like Nexus 5L doesn't support opening multiple channels.

[1] https://github.com/android/platform_hardware_ril/blob/lollipop-release/include/telephony/ril.h#L101

Comment 4

[Krzysztof Mioduszewski[:tauzen]]

Attachment: wrong-channel-number.log

New log showing that a new channel is opened but ril_worker.js returns 1 as channel number instead of 3.

Comment 5

[Krzysztof Mioduszewski[:tauzen]]

Attachment: 2015-03-10 SWP sniffing, part 1 ril log

This is a RIL log from SWP sniffing session on 2015-03-10.

Comment 6

[Krzysztof Mioduszewski[:tauzen]]

Attachment: 2015-03-10 SWP sniffing, part 2 SIM APDU traffic

APDU traffic received by the SIM card and responses sent out. This corresponds to RIL log in attachment 8575989 [details]. I've removed not relevant STATUS APDUs sent to PHONEBOOK on basic channel.

Comment 7

[Krzysztof Mioduszewski[:tauzen]]

Conclusions from analysing attachment 8575989 [details], attachment 8575995 [details] and our discussions with Edgar on IRC:
1. Please see #401 APDU in attachment 8575995 [details], it shows a successful opening of the second channel. #402 APDU (SELECT PPSE) is sent over logical channel 2 and outgoing data is actually 'open response'. This means that Nexus 5 supports opening 3 logical channels to SIM cards at same time (as expected). 

2. RIL Worker debug corresponding to point 1:
>I/Gecko   (  189): RIL Worker: [0] Received chrome message {"requestId":"{a09c51f7-31c0-4a71-a608-63cb43a4df53}","aid":"325041592E5359532E4444463031","rilMessageClientId":0,"rilMessageToken":18,"rilMessageType":"iccOpenChannel"}
>I/Gecko   (  189): RIL Worker: Outgoing parcel: 0,0,0,72,115,0,0,0,62,0,0,0,28,0,0,0,51,0,50,0,53,0,48,0,52,0,49,0,53,0,57,0,50,0,69,0,53,0,51,0,53,0,57,0,53,0,51,0,50,0,69,0,52,0,52,0,52,0,52,0,52,0,54,0,51,0,48,0,51,0,49,0,0,0,0,0
>I/Gecko   (  189): RIL Worker: Received 24 bytes.
>I/Gecko   (  189): RIL Worker: Already read 0
>I/Gecko   (  189): RIL Worker: New incoming parcel of size 20
>I/Gecko   (  189): RIL Worker: Parcel (size 20): 0,0,0,0,62,0,0,0,0,0,0,0,1,0,0,0,2,0,0,0
>I/Gecko   (  189): RIL Worker: We have at least one complete parcel.
>I/Gecko   (  189): RIL Worker: [0] Handling parcel as REQUEST_SIM_OPEN_CHANNEL
>I/Gecko   (  189): RIL Worker: [0] Setting channel number in options: 1
>I/Gecko   (  189): RIL Worker: Parcel handler didn't consume whole parcel, 4 bytes left over

Here we can see that, even though channel 2 was opened, RIL Worker sets channel ID to 1. This value is later sent to SE stack, which already has logical channel 1 opened. SE stack is not able to close logical channel 2 because of this. This is the reason of the "MissingResource" error mentioned in comment 3. To free the channel resources phone needs to be restarted.

3. As pointed out by Edgar, RIL Worker follows the Parcel structure defined in AOSP Lollipop version [0]. So in the above Parcel channel id is |1,0,0,0| and 'open response' is |2,0,0,0|.

It seems that the parcel format received by RIL Worker is wrong, 'open response' is missing and channel id is in the wrong place. We will need some support from people responsible for rild/modem here. 

[0] - https://github.com/android/platform_hardware_ril/blob/master/include/telephony/ril.h#L4045-L4064

Comment 8

[Edgar Chen [:edgar]]

(In reply to Krzysztof Mioduszewski[:tauzen] from comment #7)
> 2. RIL Worker debug corresponding to point 1:
> >I/Gecko   (  189): RIL Worker: [0] Received chrome message {"requestId":"{a09c51f7-31c0-4a71-a608-63cb43a4df53}","aid":"325041592E5359532E4444463031","rilMessageClientId":0,"rilMessageToken":18,"rilMessageType":"iccOpenChannel"}
> >I/Gecko   (  189): RIL Worker: Outgoing parcel: 0,0,0,72,115,0,0,0,62,0,0,0,28,0,0,0,51,0,50,0,53,0,48,0,52,0,49,0,53,0,57,0,50,0,69,0,53,0,51,0,53,0,57,0,53,0,51,0,50,0,69,0,52,0,52,0,52,0,52,0,52,0,54,0,51,0,48,0,51,0,49,0,0,0,0,0
> >I/Gecko   (  189): RIL Worker: Received 24 bytes.
> >I/Gecko   (  189): RIL Worker: Already read 0
> >I/Gecko   (  189): RIL Worker: New incoming parcel of size 20
> >I/Gecko   (  189): RIL Worker: Parcel (size 20): 0,0,0,0,62,0,0,0,0,0,0,0,1,0,0,0,2,0,0,0
> >I/Gecko   (  189): RIL Worker: We have at least one complete parcel.
> >I/Gecko   (  189): RIL Worker: [0] Handling parcel as REQUEST_SIM_OPEN_CHANNEL
> >I/Gecko   (  189): RIL Worker: [0] Setting channel number in options: 1
> >I/Gecko   (  189): RIL Worker: Parcel handler didn't consume whole parcel, 4 bytes left over
> 
> Here we can see that, even though channel 2 was opened, RIL Worker sets
> channel ID to 1. This value is later sent to SE stack, which already has
> logical channel 1 opened. SE stack is not able to close logical channel 2
> because of this. This is the reason of the "MissingResource" error mentioned
> in comment 3. To free the channel resources phone needs to be restarted.
> 
> 3. As pointed out by Edgar, RIL Worker follows the Parcel structure defined
> in AOSP Lollipop version [0]. So in the above Parcel channel id is |1,0,0,0|
> and 'open response' is |2,0,0,0|.

On a second though, I found I miss one thing regarding to parcel format.
The response data of OPEN_CHANNEL is a "int list". The first 4-bytes should be the length of list.
So the |1,0,0,0| is the length and |2,0,0,0| is the first field (channel id) actually.
But there is no "select response" in response data, though documentation says it will be showed in second field.

I will provide a fix for the channel id here and leave the "select response" be tracked in bug 1139837.
Thank you.

> 
> It seems that the parcel format received by RIL Worker is wrong, 'open
> response' is missing and channel id is in the wrong place. We will need some
> support from people responsible for rild/modem here. 
> 
> [0] -
> https://github.com/android/platform_hardware_ril/blob/master/include/
> telephony/ril.h#L4045-L4064

Comment 9

[Edgar Chen [:edgar]]

Attachment: Patch, v1

Comment 10

[Edgar Chen [:edgar]]

Comment on attachment 8576467 [details] [diff] [review]
Patch, v1

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

Parse the response parcel of OPEN_CHANNEL as int list and the first data is channel id.
Please see https://github.com/android/platform_hardware_ril/blob/master/include/telephony/ril.h#L4045-L4064 for the parcel format.

Hi Hsinyi, would you mind review this patch? Thank you.

Comment 11

[Hsin-Yi Tsai (she/her) [:hsinyi]]

Comment on attachment 8576467 [details] [diff] [review]
Patch, v1

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

Looks good to me!

Comment 12

[Edgar Chen [:edgar]]

Try result: https://treeherder.mozilla.org/#/jobs?repo=try&revision=4fd69fbac718

Comment 13

[Edgar Chen [:edgar]]

https://hg.mozilla.org/integration/b2g-inbound/rev/efa50202f58f

Comment 14

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/efa50202f58f