999235 - STK: Gaia is sending random Terminal Response in response to proactive commands form the STK app.

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::Settings, defect)

Description

[Nivi]

Gaia is sending Terminal Response with wrong error codes when a STK proactive command is sent either from the SIM stk app or test code. We also see a generic terminal response failure in some cases. Overall, the STK app is broken. When we click on menu items, we keep going back to the main stk menu or some other stk sub menus.

Comment 1

[Jason Smith [:jsmith]]

This is working on 1.3, right?

Comment 2

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Log traces please.

Comment 3

[Nivi]

Hi Jason,

This change doesn't affect 1.3. The change was made only on 1.4.

Thanks,
Nivi.

(In reply to Jason Smith [:jsmith] from comment #1)
> This is working on 1.3, right?

Comment 4

[Nivi]

Hi Jason,

This reply was for another bugzilla. Please ignore.
Fernando I will send you the logs shortly.

Thanks,
Nivi.

(In reply to Nivi from comment #3)
> Hi Jason,
> 
> This change doesn't affect 1.3. The change was made only on 1.4.
> 
> Thanks,
> Nivi.
> 
> (In reply to Jason Smith [:jsmith] from comment #1)
> > This is working on 1.3, right?

Comment 5

[Preeti Raghunath(:Preeti)]

CS blocking for STK and hence a+ for 1.4

Comment 6

[Nivi]

Attachment: stk_terminal_response_error.log

Hi Fernando,

PFA the logs.
This is a regression on 1.4. It was working for me couple of weeks back. I haven't tested yet on 1.3 but I will do that today and let you know.

Thanks,
Nivi.

Comment 7

[howie [:howie]]

Hi Tim, could you assign if this belongs to Gaia Settings?

Comment 8

[Tim Guan-tin Chien [:timdream] (please needinfo)]

:frsela is working on this.

Comment 9

[Preeti Raghunath(:Preeti)]

(In reply to Tim Guan-tin Chien [:timdream] (MoCo-TPE) (please ni?) from comment #8)
> :frsela is working on this.

Thanks :frsela. 

Can you please put down when we would have the fix, after your analysis?

This blocks QC CS.

Comment 10

[Nivi]

It affects 1.3 as well. I tested it today on 1.3 and I see the same issue.

Thanks,
Nivi.

Comment 11

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Hi, Nivi,

I'm looking at the logs, but if you can also provide them with Gaia level logs enabled will be great to check what is doing at higher levels ;)

Also, as some information, theorically, the STK_RESULT_UICC_SESSION_TERM_BY_USER is sent when the user press the close button on STK confirm dialogs and on visibilitychanges events in settings

STK_RESULT_NO_RESPONSE_FROM_USER if the user closes settings when a pending message should be responded (onbeforeunload event) and on timeouts

Comment 12

[Nivi]

Hi Fernando,

That seems to be the problem. Gaia is generating these key events somehow without the user pressing the close button or exiting settings. Does Gaia already has logs that I can enable? Can you share the steps if so?

If not, could you please send me a patch with debug messages added in Gaia (the code that you want to debug) and I would be happy to apply the patch and send you logs.

Thanks,
Nivi.

Comment 13

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

(In reply to Nivi from comment #12)
> Hi Fernando,
> 
> That seems to be the problem. Gaia is generating these key events somehow
> without the user pressing the close button or exiting settings. Does Gaia
> already has logs that I can enable? Can you share the steps if so?
> 
> If not, could you please send me a patch with debug messages added in Gaia
> (the code that you want to debug) and I would be happy to apply the patch
> and send you logs.
> 
> Thanks,
> Nivi.

Yes, into the developer settings menu enable Gaia Traces.

If you want to add new traces, use the DUMP() function which is used with this menu option.

Thanks

Comment 14

[Preeti Raghunath(:Preeti)]

Fernando,

Are you able to reproduce this issue?

What do we need from QC for you to proceed?

Comment 15

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

(In reply to Preeti Raghunath(:Preeti) from comment #14)
> Fernando,
> 
> Are you able to reproduce this issue?
> 

I didn't be able :(

> What do we need from QC for you to proceed?

If you reproduced it, please sent me detailed traces at GAIA and RIL level to check where is failing. If needed. If you consider more traces could be needed (before any call to stkResponse) feel free to add them ;)

Thank you

Comment 16

[Nivi]

Hi Fernando,

I am also unable to reproduce the terminal response issue on the latest build. I am seeing some other errors in STK which I am working internally to resolve.

For now, let's keep this bug open and we can close it if I can't reproduce the issue on latest builds. I will let you know if I see this again or not in the next couple of days.

Thanks,
Nivi.

Comment 17

[Anshul]

Nivi, lets close it for now and we should reopen it once all other issues you are seeing are resolved. This will help Mozilla focusing on the issues that they need to look at.

Comment 18

[Nivi]

This is definitely an issue with Gaia. Re-opening the issue.
I will upload complete logs shortly.

STR:

1. Put a STK sim card and go to STK app.
2. Click on a menu item.
3. We see the new menu show up briefly before going to the main menu screen.

Cause of the issue: 
2. Logs show the STK proactive command is being sent. Then an envelope command is sent which generates the UNSOL_PROACTIVE_COMMAND for displaying the new menu. We are ok till here until gaia sends two different terminal responses at the same time (for BACK and no response) and the new menu closes and we go back to the main menu.

Snippet of the logs -

01-01 00:30:16.669  1236  1236 I GeckoDump: [settings] sendStkResponse to message: {"iccId":"89019990001234567893","command":{"commandNumber":1,"typeOfCommand":36,"commandQualifier":0,"options":{"title":"Choose an item :","items":[{"identifier":1,"text":"Display text"},{"identifier":2,"text":"Select item"},{"identifier":3,"text":"Get input"},{"identifier":4,"text":"Get inkey"}],"presentationType":0}}}
01-01 00:30:16.669  1236  1236 I GeckoDump: [settings] sendStkResponse -- # response = {"resultCode":18}
01-01 00:30:16.669   224   224 I Gecko   : [SUB0] QCONTENT_HELPER receiveMessage: 'RIL:SendStkResponse'
01-01 00:30:16.669   224   224 D RIL     : [SUB0] [0123]> RIL_REQUEST_STK_SEND_TERMINAL_RESPONSE 810301240002028281830112

01-01 00:30:16.669  1236  1236 I GeckoDump: [settings] sendStkResponse to message: {"iccId":"89019990001234567893","command":{"commandNumber":1,"typeOfCommand":36,"commandQualifier":0,"options":{"title":"Choose an item :","items":[{"identifier":1,"text":"Display text"},{"identifier":2,"text":"Select item"},{"identifier":3,"text":"Get input"},{"identifier":4,"text":"Get inkey"}],"presentationType":0}}}
01-01 00:30:16.669  1236  1236 I GeckoDump: [settings] sendStkResponse -- # response = {"resultCode":17}
01-01 00:30:16.669  1236  1236 I GeckoDump: [settings] ICC Getting ICC for 89019990001234567893
01-01 00:30:16.669   224   224 I Gecko   : [SUB0] QCONTENT_HELPER receiveMessage: 'RIL:SendStkResponse'
01-01 00:30:16.679   224   224 D RIL     : [SUB0] [0124]> RIL_REQUEST_STK_SEND_TERMINAL_RESPONSE 810301240002028281830111

Comment 19

[Nivi]

Attachment: Sending multiple Terminal response log

This could be a STK DSDS regression. I am using a single SIM and seeing two TR's send for a UNSOL_STK_PRACTIVE command.

Comment 20

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

In the provided logs I saw to responses:

05-05 01:53:59.740  1257  1257 I GeckoDump: [settings] sendStkResponse -- # response = {"resultCode":18}
05-05 01:53:59.740  1257  1257 I GeckoDump: [settings] sendStkResponse -- # response = {"resultCode":17}

Which corresponds to this two responses:

    STK_RESULT_NO_RESPONSE_FROM_USER: 0x12,
    STK_RESULT_BACKWARD_MOVE_BY_USER: 0x11,

so both timers had been fired at the same time. I saw that this happens when we call stkResNoResponse method and is fired by the timeout defined in icc.selectTimeout.

First, I'll fix both calls (only one shall be called) but my question is about the timeout ... How many time have you defined in your build? in the calls appears like it's 0 !

Comment 21

[Anshul]

Fernando, this issue is blocking a lot of our STK test cases and wondering if you have an ETA on the fix.

Comment 22

[Nivi]

Hi Fernando,

We don't explicitly set the timeout anywhere other than our test. I am testing this using the STK app on a test SIM. The only place where the timeout is set is in gaia.
Please let me know if you have any more questions.

Thanks,
Nivi.

Comment 23

[Nivi]

Also, I am wondering if this issue is related to https://bugzilla.mozilla.org/show_bug.cgi?id=978434. Why was the fix for 978434 not ported to 1.4?

Thanks,
Nivi.

Comment 24

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Patch for master branch

Comment 25

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Attachment: Patch for 1.4 branch

Also includes the unit tests added in 978434 which are related to this one too and is nice to have them in 1.4

Comment 26

[Nivi]

Comment on attachment 8420878 [details] [review]
Patch for 1.4 branch

I tested this on 1.4. It works.

Comment 28

[Nivi]

Comment on attachment 8420875 [details] [review]
Patch for master branch

works for me. Thanks Fernando. Issue is fixed.

Comment 29

[howie [:howie]]

:vingtetun , could you proceed the review? thanks.

Comment 30

[Vivien Nicolas (:vingtetun) (:21) - (NOT reading bugmails, needinfo? please)]

Comment on attachment 8420875 [details] [review]
Patch for master branch

Looking at the patch, it is not clear to me how it solve the issue.

My understanding is that:
 Calling returnToSettingsMainMenu === Settings.currentPanel = '#root';

Not sure why it is done in stkResNoResponse and not stkResTerminate.

 Calling returnToSettingsMainMenu(true) === the same code path than before for stkResGoBack.

So how does the patch fix the issue ? (it will also be cleaner to have 2 separated functions, functions with a boolean argument usually wants to be splitted).

Comment 31

[Preeti Raghunath(:Preeti)]

Fernando,

ni to respond to comment 30 from Vivien

Comment 32

[howie [:howie]]

Hi Fernando, because this is CS blocker, can you update the new ETA? Thanks.

Comment 33

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Hi, Today I'll address Vivien's comments.
New ETA, today :p

Comment 34

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

(In reply to Vivien Nicolas (:vingtetun) (:21) (NOT reading bugmails, needinfo? please) from comment #30)
> Comment on attachment 8420875 [details] [review]
> Patch for master branch
> 
> Looking at the patch, it is not clear to me how it solve the issue.
> 
> My understanding is that:
>  Calling returnToSettingsMainMenu === Settings.currentPanel = '#root';
> 

Yes, but in some cases this is delayed.
The issue was that in the previously to this patch, only in v1.4, was that in method stkResNoResponse it responds to the SIM card and then called stkResGoBack to return to settings main menu (which produced the other and buggy STK response)

So instead of that, I moved directly to settings main menu. In order to do it in a cleaner way, I created a new method to do that (since some times is needed to delay it (move back operations) and another times should be done directly.

I created another patch for master in order to follow the same rules (a new return to Main menu method.

> Not sure why it is done in stkResNoResponse and not stkResTerminate.
> 

I forgot it ...

>  Calling returnToSettingsMainMenu(true) === the same code path than before
> for stkResGoBack.
> 

As told before, the failure is in v1.4 only. In master is implemented only to maintain coherence

> So how does the patch fix the issue ? (it will also be cleaner to have 2
> separated functions, functions with a boolean argument usually wants to be
> splitted).

Ok, I'll split them

Comment 35

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Hi vivien, Both patches updated.

I answered you in the previous comment: https://bugzilla.mozilla.org/show_bug.cgi?id=999235#c34

Comment 36

[Vivien Nicolas (:vingtetun) (:21) - (NOT reading bugmails, needinfo? please)]

Comment on attachment 8420878 [details] [review]
Patch for 1.4 branch

Ok. Makes sense. I only looked at the patch against master at the beginning so it was very unclear to me how the patch solves anything. No the logic is different on 1.4.

Comment 37

[Fernando R. Sela (no CC, needinfo please) [:frsela]]

Master patch landed: https://github.com/mozilla-b2g/gaia/commit/dfef240588147c231aa55e904f394b4c14c2c125

V1.4 rebased and waiting for travis

Comment 38

[Ryan VanderMeulen [:RyanVM]]

v1.4: https://github.com/mozilla-b2g/gaia/commit/496953dd8df331dbcdd4582cf19e34f98408d2e6

Comment 39

[Yeojin Chung [:YeojinC]]

Unable to create a test case. This bug involves the STK app.