932721 - [wasabi] It took more than 1 minute to switch CDMA mode to Automated mode

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: RIL, defect)

Description

[Peipei Cheng (needinfo if you need my action)]

Attachment: adblog.log

Build 
Gaia:     0a96b0041a6366428064df1fc9af9cba919ef67c
Gecko:    f707339bf3131c4333a9c2a52f52d669522b3125
BuildID   20131030031537
Version   26.0a2 

Steps:
1. Go to Settings->Cellular&Data ->Network operator
2. Change Network type to CDMA. After a while, 1x icon appears on the status bar
3. Change network type to Automatic
[issue] The status bar still shows 1x. It took long time to show EV although the network is always under EVDO network.

Please see attached adb logcat. The timestamp is: 10-30 18:19:12


This is similar to bug 911652. But this bug does not exist on build.
Gaia:     1e9470b9b6df630eddf1c4c8b25b3170ee786b0e
Gecko:    8c76bfd190ce7b42aa45da8096725610e48e69ed
BuildID   20130926151647
Version   26.0a2

Comment 1

[Enpei]

Hi Ken, 

Could you help to check is this still vendor issue? But based on Peipei's experiment, this is not found on 0926 build.

Comment 2

[Preeti Raghunath(:Preeti)]

Regression and 1 min is long. Perf as well. Hence koi+

Comment 3

[Ken Chang[:kenkai]]

It's a modem issue. Do you trigger the data after doing automatic network selection?

1. Modem notifies RIL that it's in evdo network at 18:18:54.125
10-30 18:18:54.125 I/Gecko   (  544): -*- RILContentHelper: Received message 'RIL:DataInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1},"type":"evdoa","signalStrength":null,"relSignalStrength":null,"state":"registered","apn":"ctnet"}}

2. Modem automatically selects 1xrtt network at 18:18:58.770
10-30 18:18:58.770 I/Gecko   (  539): -*- RILContentHelper: Received message 'RIL:DataInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1},"type":"1xrtt","signalStrength":null,"relSignalStrength":null,"state":"registered","apn":"ctnet"}}

3. Modem notifies us that it camps on EVDO network at 18:21:41.047.
10-30 18:21:41.047 I/Gecko   (  544): -*- RILContentHelper: Received message 'RIL:DataInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1},"type":"evdoa","signalStrength":-64,"relSignalStrength":100,"state":"registered","apn":"ctnet"}}

Comment 4

[Peipei Cheng (needinfo if you need my action)]

(In reply to Ken Chang from comment #3)
> It's a modem issue. Do you trigger the data after doing automatic network
> selection?
> 
> 1. Modem notifies RIL that it's in evdo network at 18:18:54.125
[pcheng] Yes, the EV appears on the status bar when the setting is "Automatic"
> 10-30 18:18:54.125 I/Gecko   (  544): -*- RILContentHelper: Received message
> 'RIL:DataInfoChanged':
> {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":
> false,"network":{"longName":"China Telecom","shortName":"China
> Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,
> "gsmCellId":-1},"type":"evdoa","signalStrength":null,"relSignalStrength":
> null,"state":"registered","apn":"ctnet"}}
> 
> 2. Modem automatically selects 1xrtt network at 18:18:58.770
[pcheng] I switch to CDMA mode, and 1x appears on status bar. 
> 10-30 18:18:58.770 I/Gecko   (  539): -*- RILContentHelper: Received message
> 'RIL:DataInfoChanged':
> {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":
> false,"network":{"longName":"China Telecom","shortName":"China
> Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,
> "gsmCellId":-1},"type":"1xrtt","signalStrength":null,"relSignalStrength":
> null,"state":"registered","apn":"ctnet"}}
> 
> 3. Modem notifies us that it camps on EVDO network at 18:21:41.047.
[pcheng] I switched to "Automatic" at 18:19:32. By EV appears at about 18:21:41. It took about two minutes to camps on EVDO network. But in last test build, the when I switch to "CDMA/EVDO" mode(the UI was not changed to Automatic), EVDO network is camped very quickly.
> 10-30 18:21:41.047 I/Gecko   (  544): -*- RILContentHelper: Received message
> 'RIL:DataInfoChanged':
> {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":
> false,"network":{"longName":"China Telecom","shortName":"China
> Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,
> "gsmCellId":-1},"type":"evdoa","signalStrength":-64,"relSignalStrength":100,
> "state":"registered","apn":"ctnet"}}

Comment 5

[Peipei Cheng (needinfo if you need my action)]

I recalled my memory. In build 0926, I lock and unlock homescreen, so EV appears more quickly. After retesting, it also took long time to change from 1x to EV when switching CDMA to Automatic. Sorry for the confusion. This should be the same reason as bug 911652.

Comment 6

[Enpei]

Hi Ken,

After Peipei’s great help running some tests, we found some crucial evidences that 932721 and 911652 may not be modem bug. I will update follow information on both bugs and remove POVB first. And please let us know any log you still need for further debugging.

1.	Bug 932721, 911652 Test step doesn’t include triggering data call after mode switch. But Android version has no such issue.
2.	Peipei run speed test after type changing and found that speed is correct but icon is wrong. (ex: after EVDO > CDMA, speed test is near 100k yet icon is EV)
3.	Both issues can be recovered by lock and unlock screen 10s after type switching. Doesn’t sound like still modem bug.

Comment 7

[Ken Chang[:kenkai]]

(In reply to Enpei from comment #6)
> Hi Ken,
> 
> After Peipei’s great help running some tests, we found some crucial
> evidences that 932721 and 911652 may not be modem bug. I will update follow
> information on both bugs and remove POVB first. And please let us know any
> log you still need for further debugging.
> 
> 1.	Bug 932721, 911652 Test step doesn’t include triggering data call after
> mode switch. But Android version has no such issue.
> 2.	Peipei run speed test after type changing and found that speed is correct
> but icon is wrong. (ex: after EVDO > CDMA, speed test is near 100k yet icon
> is EV)
> 3.	Both issues can be recovered by lock and unlock screen 10s after type
> switching. Doesn’t sound like still modem bug.
Can you provide a log? If the modem doesn't provide the notification, this issue is still in Modem...:)

Comment 8

[Ken Chang[:kenkai]]

(In reply to Ken Chang from comment #7)
Here are the reasons that I need log.
> > 1.	Bug 932721, 911652 Test step doesn’t include triggering data call after
> > mode switch. But Android version has no such issue.
Maybe, partner does a special mechanism for the network type recovery.
> > 2.	Peipei run speed test after type changing and found that speed is correct
> > but icon is wrong. (ex: after EVDO > CDMA, speed test is near 100k yet icon
> > is EV)
If modem is in EVDO network but it doesn't notify RIL, RIL won't know the network status updated.
> > 3.	Both issues can be recovered by lock and unlock screen 10s after type
> > switching. Doesn’t sound like still modem bug.
This kind of scenario will trigger RIL to issue a request to get current network status. I think RIL can get a real network type via this request.

So I need a log to make sure proceeding assumptions are true...:)

Comment 9

[Peipei Cheng (needinfo if you need my action)]

Please see attachment: https://bugzilla.mozilla.org/attachment.cgi?id=825153

Steps:
1. Change mode from Automatic to CDMA
   Timestamp 10-31 16:20:10.732
   1x appears after about 1 minute
2. Change mode from CDMA to Automatic
   Time stamp 10-31 16:22:52.335
3. EV appears after about 50s. Change type from Automatic to CDMA again
   Time stamp: 10-31 16:23:49.928 
4. Wait for a while 1X does not appear. Lock screen
   Time stamp 10-31 16:24:55.368
5. unlock homescreen
   Time stamp 10-31 16:24:59.082 
   1x appears.

Comment 10

[Ken Chang[:kenkai]]

(In reply to pcheng from comment #9)
Again, it is the modem problem...:)
> 4. Wait for a while 1X does not appear. Lock screen
>    Time stamp 10-31 16:24:55.368
1. the modem said it was in evdo network at 10-31 16:24:35.767.
10-31 16:24:35.767 I/Gecko   (  200): -*- RILContentHelper: Received message 'RIL:DataInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1},"type":"evdoa","signalStrength":null,"relSignalStrength":null,"state":"registered","apn":"ctnet"}}

2. RIL started suspend(turn off screen) procedure at 10-31 16:24:53.045.
10-31 16:24:53.045 I/Gecko   (  200): RIL Worker[0]: Received chrome message {"on":false,"rilMessageToken":21,"rilMessageType":"setScreenState"}

3. RIL asked modem to provide the network status update and got the response at 10-31 16:24:53.125.
10-31 16:24:53.125 I/Gecko   (  200): RIL Worker[0]: Handling parcel as REQUEST_DATA_REGISTRATION_STATE

4. The response from Modem told RIL that modem is in 1xrtt.
10-31 16:24:53.145 I/Gecko   (  200): -*- RILContentHelper: Received message 'RIL:DataInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1},"type":"1xrtt","signalStrength":null,"relSignalStrength":null,"state":"registered","apn":"ctnet"}}
5. Afterwords, the network type was 1xrtt.
10-31 16:25:18.712 I/Gecko   (  667): -*- RILContentHelper: Received message 'RIL:VoiceInfoChanged': {"clientId":0,"data":{"connected":true,"emergencyCallsOnly":false,"roaming":false,"network":{"longName":"China Telecom","shortName":"China Telecom","mcc":"460","mnc":"03"},"cell":{"gsmLocationAreaCode":-1,"gsmCellId":-1,"cdmaBaseStationId":51953,"cdmaBaseStationLatitude":574695,"cdmaBaseStationLongitude":1676649,"cdmaSystemId":13824,"cdmaNetworkId":3},"type":"1xrtt","signalStrength":-60,"relSignalStrength":100,"state":"registered"}}

> 5. unlock homescreen
>    Time stamp 10-31 16:24:59.082 
>    1x appears.

Comment 11

[Enpei]

Thank you, Ken. Normally will modem inform RIL? Android version doesn't have this problem. Anything FxOS still can do for this kind of bug?

Comment 12

[Ken Chang[:kenkai]]

(In reply to Enpei from comment #11)
> Thank you, Ken. Normally will modem inform RIL? Android version doesn't have
Yes, since the network type is changed, modem have to update RIL the new network type.
> this problem. Anything FxOS still can do for this kind of bug?
It depends on OEM. Since manufacturers knows their phone's problem and do workaround for their phone.
However, I wonder if it is appropriate for us to do this. My suggestion is to leave this device specific implementation to OEM.

Comment 13

[Enpei]

Based on comment 12, add POVB in whiteboard.

Comment 14

[Preeti Raghunath(:Preeti)]

Do not block on POVB.

Comment 15

[bhavana bajaj [:bajaj]]

:khu blocking minus the issue as its recently identified to be POVB which we did not know when initially blocked on.

Comment 16

[Peipei Cheng (needinfo if you need my action)]

Attachment: qcril_adblogcat.log

Using QCRIL build, it also take some time to change network from CDMA to Automatic. But the time is shorter than MOZRIL build.
Test build: 20131120031537

Please see attached adb logcat file.

1. CDMA -> Automatic   11-21 18:31:00.870

Comment 17

[Ken Chang[:kenkai]]

POVB and we don't have a CDMA phone launched yet. It is not a regression.

Comment 18

[BMO Automation]

Firefox OS is not being worked on