On a fresh boot, device might show "No SIM card" while there is really one. 100% reproductibility at least on Nexus S and Peak. After stop b2g/start b2g, SIM card is detected. Looking at Gecko RIL logs, the SIM card status detected is fine on my Nexus S (pinRequired), but debug in SIM Slot shows no event coming at all, only: E/GeckoConsole( 77): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391929871338.441] publish: created STR: 0. Device powered, with SIM card inserted and visible 1. Long press power, select "Power off" 2. Wait a couple of seconds, then power on. 3. Let B2G boot Expected: SIM card detected, either registering on network or asking PIN code. Actual: No SIM card detected. Having a PIN code set or not has no impact.

Logcat when the SIM is detected, after a stop/start of b2g: alex@portable-alex:~/codaz/Mozilla/b2g/gaia$ adb logcat | egrep -i simslot E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:26 in ssm_init: SIMSlotManager: init E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:31 in ssm_init: SIMSlotManager: has IccManager E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:35 in ssm_init: SIMSlotManager: conns: 1 E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:40 in ssm_init: SIMSlotManager: iterating conns E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:42 in iterator: SIMSlotManager: conn: [object MozMobileConnection] -- index: 0 E/GeckoConsole( 403): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391930550831.263] publish: created E/GeckoConsole( 403): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:47 in ssm_init: SIMSlotManager: add iccdetected E/GeckoConsole( 403): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391930550828.553] publish: updated E/GeckoConsole( 403): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391930550828.532] publish: iccinfochange E/GeckoConsole( 403): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391930550828.517]pinRequired Logcat after a frehs boot: alex@portable-alex:~/codaz/Mozilla/b2g/gaia$ adb logcat | egrep -i simslot - waiting for device - E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:26 in ssm_init: SIMSlotManager: init E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:31 in ssm_init: SIMSlotManager: has IccManager E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:35 in ssm_init: SIMSlotManager: conns: 1 E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:40 in ssm_init: SIMSlotManager: iterating conns E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:42 in iterator: SIMSlotManager: conn: [object MozMobileConnection] -- index: 0 E/GeckoConsole( 77): Content JS LOG at app://system.gaiamobile.org/js/simslot.js:116 in SIMSlot.prototype.debug: [SIMSLOT][0][-1391930680659.305] publish: created E/GeckoConsole( 77): Content JS DEBUG at app://system.gaiamobile.org/js/simslot_manager.js:47 in ssm_init: SIMSlotManager: add iccdetected

Hsin-Yi, Szu-Yu, I'm wondering if this is not a regression from bug 963054. As far as I tested, I don't reproduce this issue anymore when applying those changes: > diff --git a/dom/system/gonk/ril_worker.js b/dom/system/gonk/ril_worker.js > index f9ef93d..76f8084 100644 > --- a/dom/system/gonk/ril_worker.js > +++ b/dom/system/gonk/ril_worker.js > @@ -3105,9 +3105,7 @@ RilObject.prototype = { > this.appType = app.app_type; > this.iccInfo.iccType = GECKO_CARD_TYPE[this.appType]; > // Try to get iccId only when cardState left GECKO_CARDSTATE_UNDETECTED. > - if (iccStatus.cardState === CARD_STATE_PRESENT && > - (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > - this.cardState === GECKO_CARDSTATE_UNDETECTED)) { > + if (iccStatus.cardState === CARD_STATE_PRESENT) { > ICCRecordHelper.readICCID(); > }

I don't self-build so I'm no help here, sorry :)

(In reply to Alexandre LISSY :gerard-majax from comment #2) > Hsin-Yi, Szu-Yu, I'm wondering if this is not a regression from bug 963054. > > As far as I tested, I don't reproduce this issue anymore when applying those > changes: > Hmm, interesting try... Before bug 963054 we had only one const GECKO_CARDSTATE_UNDETECTED which covered the definitions of "GECKO_CARDSTATE_UNINITIALIZED" and "GECKO_CARDSTATE_UNDETECTED" afterwards. We introduced GECKO_CARDSTATE_UNINITIALIZED to make things clearer and the logic before and after bug 963054 is the same. So it's not obvious to me this is a regression from that. We call readICCID() only when card state changes from uninitialized/undetected to present. Wondering if Peak or Nexus S sends another cardstate X between those so that we never get the chance to readICCID(). Maybe you could help provide RIL log. > > diff --git a/dom/system/gonk/ril_worker.js b/dom/system/gonk/ril_worker.js > > index f9ef93d..76f8084 100644 > > --- a/dom/system/gonk/ril_worker.js > > +++ b/dom/system/gonk/ril_worker.js > > @@ -3105,9 +3105,7 @@ RilObject.prototype = { > > this.appType = app.app_type; > > this.iccInfo.iccType = GECKO_CARD_TYPE[this.appType]; > > // Try to get iccId only when cardState left GECKO_CARDSTATE_UNDETECTED. > > - if (iccStatus.cardState === CARD_STATE_PRESENT && > > - (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > > - this.cardState === GECKO_CARDSTATE_UNDETECTED)) { > > + if (iccStatus.cardState === CARD_STATE_PRESENT) { > > ICCRecordHelper.readICCID(); > > }

Alexandre, The following lines are the original code before bug 963054 and I think the patch didn't change any logic for this part. if (this.cardState === GECKO_CARDSTATE_UNDETECTED && iccStatus.cardState === CARD_STATE_PRESENT) { ICCRecordHelper.readICCID(); } This is the fix you do in Comment 2. The logic is actually different from the above one. if (iccStatus.cardState === CARD_STATE_PRESENT) { ICCRecordHelper.readICCID(); } Could you build a gecko with version prior than bug 963054. I am wondering whether it was OK before and we just broke something in bug 963054. Otherwise, it might be another issue, which is not related to bug 963054.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #4) > (In reply to Alexandre LISSY :gerard-majax from comment #2) > > Hsin-Yi, Szu-Yu, I'm wondering if this is not a regression from bug 963054. > > > > As far as I tested, I don't reproduce this issue anymore when applying those > > changes: > > > > Hmm, interesting try... > > Before bug 963054 we had only one const GECKO_CARDSTATE_UNDETECTED which > covered the definitions of "GECKO_CARDSTATE_UNINITIALIZED" and > "GECKO_CARDSTATE_UNDETECTED" afterwards. We introduced > GECKO_CARDSTATE_UNINITIALIZED to make things clearer and the logic before > and after bug 963054 is the same. So it's not obvious to me this is a > regression from that. > > We call readICCID() only when card state changes from > uninitialized/undetected to present. Wondering if Peak or Nexus S sends > another cardstate X between those so that we never get the chance to > readICCID(). Maybe you could help provide RIL log. > > > > diff --git a/dom/system/gonk/ril_worker.js b/dom/system/gonk/ril_worker.js > > > index f9ef93d..76f8084 100644 > > > --- a/dom/system/gonk/ril_worker.js > > > +++ b/dom/system/gonk/ril_worker.js > > > @@ -3105,9 +3105,7 @@ RilObject.prototype = { > > > this.appType = app.app_type; > > > this.iccInfo.iccType = GECKO_CARD_TYPE[this.appType]; > > > // Try to get iccId only when cardState left GECKO_CARDSTATE_UNDETECTED. > > > - if (iccStatus.cardState === CARD_STATE_PRESENT && > > > - (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > > > - this.cardState === GECKO_CARDSTATE_UNDETECTED)) { > > > + if (iccStatus.cardState === CARD_STATE_PRESENT) { > > > ICCRecordHelper.readICCID(); > > > } I have the logs from the gecko RIL, but they were not helpful.

(In reply to Szu-Yu Chen [:aknow] from comment #5) > Alexandre, > > The following lines are the original code before bug 963054 and I think the > patch didn't change any logic for this part. > > if (this.cardState === GECKO_CARDSTATE_UNDETECTED && > iccStatus.cardState === CARD_STATE_PRESENT) { > ICCRecordHelper.readICCID(); > } > > This is the fix you do in Comment 2. The logic is actually different from > the above one. > > if (iccStatus.cardState === CARD_STATE_PRESENT) { > ICCRecordHelper.readICCID(); > } > > Could you build a gecko with version prior than bug 963054. I am wondering > whether it was OK before and we just broke something in bug 963054. > Otherwise, it might be another issue, which is not related to bug 963054. It has changes from: (this.cardState === GECKO_CARDSTATE_UNDETECTED && iccStatus.cardState === CARD_STATE_PRESENT) to : (iccStatus.cardState === CARD_STATE_PRESENT && (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || this.cardState === GECKO_CARDSTATE_UNDETECTED)). I reverted to (this.cardState === GECKO_CARDSTATE_UNDETECTED && iccStatus.cardState === CARD_STATE_PRESENT) and I reproduce the issue, so probably you are right and we are just exposing a long standing issue.

I reverted my hack, and added some debug prior the if so the code looks like this: > 3107 // Try to get iccId only when cardState left GECKO_CARDSTATE_UNDETECTED. > + 3108 debug("About to call ICCRecordHelper.readICCID :: this.cardState=" + this.cardState); > + 3109 debug("About to call ICCRecordHelper.readICCID :: iccStatus.cardState=" + iccStatus.cardState); > 3110 if (iccStatus.cardState === CARD_STATE_PRESENT && > 3111 (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > . 3112 this.cardState === GECKO_CARDSTATE_UNDETECTED)) { > 3113 ICCRecordHelper.readICCID(); > 3114 } > This is what I get: $ grep readICCID icc.nexus.log I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=uninitialized I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1 I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: this.cardState=pinRequired I/Gecko ( 77): RIL Worker: About to call ICCRecordHelper.readICCID :: iccStatus.cardState=1

I get correct behavior if I add handling for pin required and puk required states.

(In reply to Alexandre LISSY :gerard-majax from comment #9) > Created attachment 8382036 [details] [diff] [review] > ril.cardState.patch > > I get correct behavior if I add handling for pin required and puk required > states. Thanks for the patch. I am working on urgent 2/28 bugs and won't have bandwidth until then, sorry. I'll get back to you afterwards.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #10) > (In reply to Alexandre LISSY :gerard-majax from comment #9) > > Created attachment 8382036 [details] [diff] [review] > > ril.cardState.patch > > > > I get correct behavior if I add handling for pin required and puk required > > states. > Thanks for the patch. I am working on urgent 2/28 bugs and won't have > bandwidth until then, sorry. I'll get back to you afterwards. No problem, we are all in the same ship :). I can live for some time with this small local change.

Comment on attachment 8382036 [details] [diff] [review] ril.cardState.patch Review of attachment 8382036 [details] [diff] [review]: ----------------------------------------------------------------- Sorry for being late. ::: dom/system/gonk/ril_worker.js @@ +3108,5 @@ > if (iccStatus.cardState === CARD_STATE_PRESENT && > (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > + this.cardState === GECKO_CARDSTATE_UNDETECTED || > + this.cardState === GECKO_CARDSTATE_PIN_REQUIRED || > + this.cardState === GECKO_CARDSTATE_PUK_REQUIRED)) { Per your investigation on comment 8, there's indeed a transition from "this.cardState=uninitialized" to "iccStatus.cardState=1". So at that time, readICCID() should be called, I don't see obvious reasons why we need to have GECKO_CARDSTATE_PIN_REQUIRED and GECKO_CARDSTATE_PUK_REQUIRED. Could you explain more? Otherwise, I doubt this patch doesn't point to the root cause. Thank you.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #12) > Comment on attachment 8382036 [details] [diff] [review] > ril.cardState.patch > > Review of attachment 8382036 [details] [diff] [review]: > ----------------------------------------------------------------- > > Sorry for being late. > > ::: dom/system/gonk/ril_worker.js > @@ +3108,5 @@ > > if (iccStatus.cardState === CARD_STATE_PRESENT && > > (this.cardState === GECKO_CARDSTATE_UNINITIALIZED || > > + this.cardState === GECKO_CARDSTATE_UNDETECTED || > > + this.cardState === GECKO_CARDSTATE_PIN_REQUIRED || > > + this.cardState === GECKO_CARDSTATE_PUK_REQUIRED)) { > > Per your investigation on comment 8, there's indeed a transition from > "this.cardState=uninitialized" to "iccStatus.cardState=1". So at that time, > readICCID() should be called, I don't see obvious reasons why we need to > have GECKO_CARDSTATE_PIN_REQUIRED and GECKO_CARDSTATE_PUK_REQUIRED. Could > you explain more? Otherwise, I doubt this patch doesn't point to the root > cause. Thank you. I re-did a debug log. You are right, we are doing the call: 129 I/Gecko ( 77): RIL Worker: iccStatus.cardState=1 -- this.cardState=uninitialized 130 I/Gecko ( 77): RIL Worker: Calling ICCRecordHelper.readICCID() 131 I/Gecko ( 77): RIL Worker: readICCID: perform ICCIO But, 212 I/Gecko ( 77): RIL Worker: REQUEST_SIM_IO: length=0 213 I/Gecko ( 77): RIL Worker: REQUEST_SIM_IO: options={"fileId":12258,"type":0,"command":192,"pathId":"3f00","p1":0,"p2":0,"p3":15,"rilRequestType":28,"rilRequestError":1} 214 I/Gecko ( 77): RIL Worker: [0] ICC I/O Error code RadioNotAvailable EF id = 2fe2 command = c0 fileId 12258 is 2fe2, which is the id of icc record. So this is the root of the race condition.

So after debugging a bit again, checking the radio state helps a lot :)

(In reply to Alexandre LISSY :gerard-majax from comment #14) > Created attachment 8384510 [details] [diff] [review] > ril.cardState.patch > > So after debugging a bit again, checking the radio state helps a lot :) Hey Alexandre, Adding check on radio_state gives a useful hint. Thanks for the information. :) However, I am not sure if this is the right solution. An interesting thing is that typically cardState becomes present after radio is available. Then how come an error "RadioNotAvailable" appears when we try to readICCID() with cardState present? I need more context before providing any further feedback. As I don't have nexus S on hand, please help provide me the log with RIL debugger enabled, i.e. "adb logcat -b radio -b main -v time". Hope we get more ideas then. Thank you!

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #15) > (In reply to Alexandre LISSY :gerard-majax from comment #14) > > Created attachment 8384510 [details] [diff] [review] > > ril.cardState.patch > > > > So after debugging a bit again, checking the radio state helps a lot :) > > Hey Alexandre, > > Adding check on radio_state gives a useful hint. Thanks for the information. > :) > > However, I am not sure if this is the right solution. An interesting thing > is that typically cardState becomes present after radio is available. Then > how come an error "RadioNotAvailable" appears when we try to readICCID() > with cardState present? I need more context before providing any further > feedback. > > As I don't have nexus S on hand, please help provide me the log with RIL > debugger enabled, i.e. "adb logcat -b radio -b main -v time". Hope we get > more ideas then. Thank you! Well I already have the log, just lacks timestamps.

RIL|RadioInterface log

(In reply to Alexandre LISSY :gerard-majax from comment #17) > Created attachment 8384549 [details] > ril.log > > RIL|RadioInterface log Thanks for the log! I discussed this issue with Edgar. We conjecture [1] seems the line triggering the problem. IMO we shouldn't expect retrieving correct ICCStatus upon an unsolicited event for voice network state. I'd like to think about the possibility of removing the line. Could you mark the line and give it a try to see if that helps resolve the problem? Thank you. [1] http://hg.mozilla.org//mozilla-central/annotate/cfc63f40409d/dom/system/gonk/ril_worker.js#l6410

Comment on attachment 8384510 [details] [diff] [review] ril.cardState.patch Review of attachment 8384510 [details] [diff] [review]: ----------------------------------------------------------------- I don't think we should do this. It could affect fugu. Please see comment 18 and give it a try.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #18) > (In reply to Alexandre LISSY :gerard-majax from comment #17) > > Created attachment 8384549 [details] > > ril.log > > > > RIL|RadioInterface log > > Thanks for the log! > > I discussed this issue with Edgar. We conjecture [1] seems the line > triggering the problem. IMO we shouldn't expect retrieving correct ICCStatus > upon an unsolicited event for voice network state. I'd like to think about > the possibility of removing the line. Could you mark the line and give it a > try to see if that helps resolve the problem? Thank you. > > [1] > http://hg.mozilla.org//mozilla-central/annotate/cfc63f40409d/dom/system/gonk/ > ril_worker.js#l6410 Of course. Your bet is to revert my workaround and comment this line then ? I'll try it asap.

(In reply to Alexandre LISSY :gerard-majax from comment #20) > (In reply to Hsin-Yi Tsai [:hsinyi] from comment #18) > > (In reply to Alexandre LISSY :gerard-majax from comment #17) > > > Created attachment 8384549 [details] > > > ril.log > > > > > > RIL|RadioInterface log > > > > Thanks for the log! > > > > I discussed this issue with Edgar. We conjecture [1] seems the line > > triggering the problem. IMO we shouldn't expect retrieving correct ICCStatus > > upon an unsolicited event for voice network state. I'd like to think about > > the possibility of removing the line. Could you mark the line and give it a > > try to see if that helps resolve the problem? Thank you. > > > > [1] > > http://hg.mozilla.org//mozilla-central/annotate/cfc63f40409d/dom/system/gonk/ > > ril_worker.js#l6410 > > Of course. Your bet is to revert my workaround and comment this line then ? Yes, you got my point. > > I'll try it asap. Waiting for your response!

So, after reverting my changes and commenting this line, I do see the SIM card being detected, asking for PIN, but somehow it stays in this status: SIM PIN is correctly unlocked (I can make and receive calls), but the system (settings app, dialer) still see it as being pin locked.

So, as documented in the previous comment, the suggested change helps but I then get into a state where the new SIM card status, after unlocking with PIN code, is not updated. If I force query an ICC status update in the SIM PIN/PUK handler code, it gets correctly updated.

RIL log with your suggested changes.

(In reply to Alexandre LISSY :gerard-majax from comment #23) > Created attachment 8385284 [details] [diff] [review] > ril.cardState.patch > > So, as documented in the previous comment, the suggested change helps but I > then get into a state where the new SIM card status, after unlocking with > PIN code, is not updated. > > If I force query an ICC status update in the SIM PIN/PUK handler code, it > gets correctly updated. Oh... looks like the hardware solution of nexus s is different from other devices. I talked with Edgar again :) Currently we map radio_state into rough categories that leads to lack of details. We need to distinguish radio_state_sim_*. I'll provide a test patch later. Hopefully this issue is able to be solved.

Not map radioState into rough categories

Comment on attachment 8385938 [details] [diff] [review] WIP Review of attachment 8385938 [details] [diff] [review]: ----------------------------------------------------------------- Hi Alexandre, please help verify this patch, seeing if it resolves this issue. Thanks!!!

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #25) > (In reply to Alexandre LISSY :gerard-majax from comment #23) > > Created attachment 8385284 [details] [diff] [review] > > ril.cardState.patch > > > > So, as documented in the previous comment, the suggested change helps but I > > then get into a state where the new SIM card status, after unlocking with > > PIN code, is not updated. > > > > If I force query an ICC status update in the SIM PIN/PUK handler code, it > > gets correctly updated. > > Oh... looks like the hardware solution of nexus s is different from other > devices. I talked with Edgar again :) Currently we map radio_state into > rough categories that leads to lack of details. We need to distinguish > radio_state_sim_*. I'll provide a test patch later. Hopefully this issue is > able to be solved. That would make sense at least. I'll test it asap !

So your WIP does not work, but combining WIP that adds those new states, AND removing the previously suggested line as in comment 18, I get everything working as expected: - sim card detected - pin code asked - sim card status updated after entering pin code

Attached is the RIL log with WIP only applied. As documented, it is not enough. Adding changes from comment 18 makes everything working correctly.

(In reply to Alexandre LISSY :gerard-majax from comment #29) > So your WIP does not work, but combining WIP that adds those new states, AND > removing the previously suggested line as in comment 18, I get everything > working as expected: > - sim card detected > - pin code asked > - sim card status updated after entering pin code Oh... yes, I forgot to add comment 18 in WIP. We must have it! Thanks for reminding :)

Addressed comment 18.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #32) > Created attachment 8386055 [details] [diff] [review] > WIP - v2 > > Addressed comment 18. I think this patch is quite ready for review. Alexandre, not sure if I should file another gecko bug for the patch?

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #33) > (In reply to Hsin-Yi Tsai [:hsinyi] from comment #32) > > Created attachment 8386055 [details] [diff] [review] > > WIP - v2 > > > > Addressed comment 18. > > I think this patch is quite ready for review. > > Alexandre, not sure if I should file another gecko bug for the patch? No, I think that we are still working on the same issue, it's just that I first thought it was a SIM slot manager issue :)

(In reply to Alexandre LISSY :gerard-majax from comment #34) > (In reply to Hsin-Yi Tsai [:hsinyi] from comment #33) > > (In reply to Hsin-Yi Tsai [:hsinyi] from comment #32) > > > Created attachment 8386055 [details] [diff] [review] > > > WIP - v2 > > > > > > Addressed comment 18. > > > > I think this patch is quite ready for review. > > > > Alexandre, not sure if I should file another gecko bug for the patch? > > No, I think that we are still working on the same issue, it's just that I > first thought it was a SIM slot manager issue :) Cool~ so change the component from Gaia::System to RIL?

In summary: 1) not getICCStatus() in the handler of UNSOLICITED_RESPONSE_VOICE_NETWORK_STATE_CHANGED 2) not map radioState into rough categories, should keep distinct details instead 3) getICCStatus() when radio is available or when radio is turned off (so that we can get card_undetected in some devices)

Remove self debug log in v1.

Comment on attachment 8386713 [details] [diff] [review] WIP - part1 Review of attachment 8386713 [details] [diff] [review]: ----------------------------------------------------------------- Hi Edgar and Yoshi, The symptom of this issue is: we query iccStatus when radio is not ready. It's okay to get iccStatus and get cardstate updated. However, request_sim_io fails at [1] due to radio not ready. With more debug, [2] calling getICCStatus() leads to the issue. IMO we shouldn't query iccStatus when voice changes. We should, instead, query it when radio changes or icc changes. Also, our code currently maps radioState reported from modem into a rough category that makes us miss details and distinctions. For example, in the case of Nexus S, modem sends out radio state of RADIO_STATE_SIM_READY, RADIO_STATE_SIM_NOT_READY or RADIO_STATE_SIM_LOCKED_OR_ABSENT but our code [3] abstracts the differences. In summary, the patch does the followings: 1) not getICCStatus() in the handler of UNSOLICITED_RESPONSE_VOICE_NETWORK_STATE_CHANGED 2) not map radioState into rough categories, should keep distinct details instead 3) getICCStatus() when radio is available or when radio is turned off (so that we can get card_undetected in some devices) Please help review it, thanks! [1] http://hg.mozilla.org//mozilla-central/annotate/d2dac18d0562/dom/system/gonk/ril_worker.js#l3174 [2] http://hg.mozilla.org//mozilla-central/annotate/d2dac18d0562/dom/system/gonk/ril_worker.js#l6411 [3] http://hg.mozilla.org//mozilla-central/annotate/d2dac18d0562/dom/system/gonk/ril_worker.js#l6331

Comment on attachment 8386713 [details] [diff] [review] WIP - part1 Review of attachment 8386713 [details] [diff] [review]: ----------------------------------------------------------------- Hi Alexandra, Minor changes after WIP (v1). It would be better to have your help on testing nexus S again. :)

Comment on attachment 8386713 [details] [diff] [review] WIP - part1 Review of attachment 8386713 [details] [diff] [review]: ----------------------------------------------------------------- When card is unlocked, the SIM_STATUS_CHANGED unsolicited should be called, not RADIO_STATE_CHANGED, Also the RADIO_STATE_SIM_NOT_READY, ...etc constants are deprecated now, the patch here is likely going back to the older version of RIL. I think we should check why SIM_STATUS_CHANGED won't be called first.

(In reply to Yoshi Huang[:allstars.chh] from comment #41) > Comment on attachment 8386713 [details] [diff] [review] > WIP - part1 > > Review of attachment 8386713 [details] [diff] [review]: > ----------------------------------------------------------------- > > When card is unlocked, the SIM_STATUS_CHANGED unsolicited should be called, > not RADIO_STATE_CHANGED, > Also the RADIO_STATE_SIM_NOT_READY, ...etc constants are deprecated now, > the patch here is likely going back to the older version of RIL. > > I think we should check why SIM_STATUS_CHANGED won't be called first. I don't see 'RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED' in the previous log Alexandra provided. Let's look into "-b radio" then. Hi Alexnadre, please help provide the log with "-b radio -b main" parameters for the cases: 1) reboot 2) reboot with sim pin enabled 3) unlock sim pin 4) turn on airplane mode and turn off Thank you!

Comment on attachment 8386713 [details] [diff] [review] WIP - part1 Try to answer yoshi's question first ...

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #42) > (In reply to Yoshi Huang[:allstars.chh] from comment #41) > > Comment on attachment 8386713 [details] [diff] [review] > > WIP - part1 > > > > Review of attachment 8386713 [details] [diff] [review]: > > ----------------------------------------------------------------- > > > > When card is unlocked, the SIM_STATUS_CHANGED unsolicited should be called, > > not RADIO_STATE_CHANGED, > > Also the RADIO_STATE_SIM_NOT_READY, ...etc constants are deprecated now, > > the patch here is likely going back to the older version of RIL. > > > > I think we should check why SIM_STATUS_CHANGED won't be called first. > > I don't see 'RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED' in the previous log > Alexandra provided. Let's look into "-b radio" then. > > Hi Alexnadre, please help provide the log with "-b radio -b main" parameters > for the cases: > 1) reboot > 2) reboot with sim pin enabled > 3) unlock sim pin > 4) turn on airplane mode and turn off > > Thank you! More, it would be great help to find out when "RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED" is called.

Please, what's the actual patch to apply in order to test the solution? thank you in advance

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #42) > (In reply to Yoshi Huang[:allstars.chh] from comment #41) > > Comment on attachment 8386713 [details] [diff] [review] > > WIP - part1 > > > > Review of attachment 8386713 [details] [diff] [review]: > > ----------------------------------------------------------------- > > > > When card is unlocked, the SIM_STATUS_CHANGED unsolicited should be called, > > not RADIO_STATE_CHANGED, > > Also the RADIO_STATE_SIM_NOT_READY, ...etc constants are deprecated now, > > the patch here is likely going back to the older version of RIL. > > > > I think we should check why SIM_STATUS_CHANGED won't be called first. > > I don't see 'RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED' in the previous log > Alexandra provided. Let's look into "-b radio" then. > > Hi Alexnadre, please help provide the log with "-b radio -b main" parameters > for the cases: > 1) reboot > 2) reboot with sim pin enabled > 3) unlock sim pin > 4) turn on airplane mode and turn off > > Thank you! The logs I provided already covers 1 to 3.

But it's not radio log :)

adb logcat -b radio -b main without patch applied, sim card not detected

adb logcat -b radio -b main without patch, enabling/disabling airplane mode

adb logcat -b radio -b main with patch, pin asked

adb logcat -b radio -b main with patch, entering pin and unlocking sim

adb logcat -b radio -b main with patch, enabling/disabling airplane mode

Verifying that this issue is still present in the latest v1.3 builds available from Geeksphone on my Peak. Switching airplane mode on/off fixes the issue til the next reboot. Let me know if I can help with anything. dkl

PM Triage: Can QA confirm the latest on if this is happening on any of our portfolio devices? (besides Nexus and Peak)

QA Wanted for comment 54 - try reproducing this on Buri.

I don't reproduce this issue on latest Buri v1.4, The SIM is detected immediately upon reboots. v1.4 Environmental Variables: Device: Buri v1.4 MOZ BuildID: 20140307040203 Gaia: 04eb7996543f114133d1367f834a4d88b68c60ac Gecko: b0e7f63c2138 Version: 30.0a1 Firmware Version: v1.2-device.cfg Same results on latest Buri v1.3 v1.3 Environmental Variables: Device: Buri v1.3 MOZ BuildID: 20140307004004 Gaia: e8bf7326ce5ed63bc8ef8b2cff1eba094887b9bf Gecko: 4efa30fe00e7 Version: 28.0 Firmware Version: v1.2-device.cfg

Bumping to backlog for not being reproducible on a production device.

I hit this issue while dogfooding the latest nightly build on my Peak in the last few days; I must it's quite annoying as it's 100% reproducible.

Hsin-Yi, please note that one contributor helping on Nexus S (shadeimi in needinfo?) is experiencing this on his device. He also noticed that the current patch works but only with one of its SIM card, not with the other. Shadeimi, it would be very helpful if you could provide logcat with RIL debug enabled in both cases.

Sorry for late response. I was occupied by a workweek last week. I checked with the log again and didn't see expected parcel "RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED" being sent when card state changes. This behaviour seems not follow latest AOSP ril.h. To meet Nexus S *old* implementation, my patch is turning our moz implementation back to older RIL version (some constants are even deprecated), but this is not what we really want as Yoshi commented. I don't have better ideas of how to deal with this old vendor implementation. I am even wondering whether we could and we should fix this on gecko. Since this is not 1.4+ I'd need to work on other issues with higher priority. I am sorry about that.

Hi, this is the RIL logfile for my H3G sim card -> http://pastebin.com/qLgR8AQ0

It is neither a 1.4 target feature nor a 1.4+ bug. I don't think we need to set a target for this bug. But if I am wrong, please feel free to correct it. Thanks.

(In reply to Jason Smith [:jsmith] from comment #57) > Bumping to backlog for not being reproducible on a production device. We're getting this same error on Buri devices. The symptoms are: At boot time the SIM isn't recognized, enabling and disabling the airplane mode makes the device see the SIM. The thing is that there are devices that work correctly always, and other that fail always, both with the same build. Oh, and the devices that fail always work correctly when brought back to the stock 1.1.

(In reply to Antonio Manuel Amaya Calvo (:amac) from comment #63) > (In reply to Jason Smith [:jsmith] from comment #57) > > Bumping to backlog for not being reproducible on a production device. > > We're getting this same error on Buri devices. The symptoms are: At boot > time the SIM isn't recognized, enabling and disabling the airplane mode > makes the device see the SIM. The thing is that there are devices that work > correctly always, and other that fail always, both with the same build. Oh, > and the devices that fail always work correctly when brought back to the > stock 1.1. The Buri-specific issue is a recent regression on trunk - see bug 988979. This issue targets the non-production device issue present.

(In reply to Jason Smith [:jsmith] from comment #64) > (In reply to Antonio Manuel Amaya Calvo (:amac) from comment #63) > > (In reply to Jason Smith [:jsmith] from comment #57) > > > Bumping to backlog for not being reproducible on a production device. > > > > We're getting this same error on Buri devices. The symptoms are: At boot > > time the SIM isn't recognized, enabling and disabling the airplane mode > > makes the device see the SIM. The thing is that there are devices that work > > correctly always, and other that fail always, both with the same build. Oh, > > and the devices that fail always work correctly when brought back to the > > stock 1.1. > > The Buri-specific issue is a recent regression on trunk - see bug 988979. > This issue targets the non-production device issue present. Hmm no, I don't think we're seeing the same problem then. We've been getting this problem on several of our development Buris since... at least one month ago. Strangely enough, the same build works on some devices and fails to work on another ones (which work correctly with the stock 1.1).

(In reply to aniellob from comment #61) > Hi, > > this is the RIL logfile for my H3G sim card -> http://pastebin.com/qLgR8AQ0 No RIL_UNSOL_RESPONSE_SIM_STATUS_CHANGED delivered to gecko by modem. Seems an old RIL issue.

(In reply to Jason Smith [:jsmith] from comment #64) > (In reply to Antonio Manuel Amaya Calvo (:amac) from comment #63) > > (In reply to Jason Smith [:jsmith] from comment #57) > > > Bumping to backlog for not being reproducible on a production device. > > > > We're getting this same error on Buri devices. The symptoms are: At boot > > time the SIM isn't recognized, enabling and disabling the airplane mode > > makes the device see the SIM. The thing is that there are devices that work > > correctly always, and other that fail always, both with the same build. Oh, > > and the devices that fail always work correctly when brought back to the > > stock 1.1. > > The Buri-specific issue is a recent regression on trunk - see bug 988979. > This issue targets the non-production device issue present. I can repro this 100% of the time on a buri that has the patches from bug 988979 and deps (today's gaia master/gecko master). :amac's description of the problem, re. airplane mode is what happens to me. In light of this, I think we should reconsider the priority or open a new bug that is buri-specific (although if we are seeing a race, as it seems implied in a couple comments, it might very well happen everywhere if we are unlucky). Let me know if I can be of any help (logs/patches testing/etc.), I can repro _very_ easily on my buri.

That's strange - I'm not seeing this on the latest master. What base image are you running for Buri?

OTA updates, updated every day, I can still repro.

The FOTA updates are only touching Gecko and Gaia. I have no idea what base version Paul is running.

My current workaround.

Can we just land this? Dogfooding is painful with this bug.

Is it still current?

(In reply to Julien Wajsberg [:julienw] (PTO 08/20 -> 09/15; contact schung instead) from comment #73) > Is it still current? I haven't experienced this issue on my Peak for a while but due to the nature of the bug it could be just by luck.

(In reply to Julien Wajsberg [:julienw] (PTO 08/20 -> 09/15; contact schung instead) from comment #73) > Is it still current? I have a local hack for my Nexus S so I can't tell precisely.

(In reply to Gabriele Svelto [:gsvelto] from comment #74) > (In reply to Julien Wajsberg [:julienw] (PTO 08/20 -> 09/15; contact schung > instead) from comment #73) > > Is it still current? > > I haven't experienced this issue on my Peak for a while but due to the > nature of the bug it could be just by luck. I can confirm I have not seen this for a while on my Peak, however: - I'm using Geeksphone's updates, so maybe they have a local hack - Removing the hack from my Nexus S, I still have the issue

Alex, are you still working on this? Can we close it?

(In reply to Gregor Wagner [:gwagner] from comment #77) > Alex, are you still working on this? Can we close it? Well I think we should keep it opened, I'm still having a look at this, but this may just be limited to some devices.

Unassigning as I'm stopping dogfooding Nexus S.

This bug results from that our gecko doesn't support old deprecated AOSP ril version (RIL v6, ICS based), and as we've moved to AOSP-L (RIL v11) we don't go back to support the deprecated version. Going to close as WONTFIX.