Both modem interfaces go momentarily down if one SIM goes PUK locked

I see the two ModemAdded signals, do the modem instances completely disappear, and if so, why aren't there corresponding ModemRemoved signals?

Also, can you check /var/crash to see if maybe ofonod is crashing? If this happens, you also should see the PID change in the ofono messages in /var/log/syslog.

There is crash.

dmesg gives following:

[ 104.611156] (0)[825:init]init: PropSet Error:[ro.ril.ecclist:112,911] ro.* properties may NEVER be modified once set
[ 104.946673] (0)[1200:hci_stpd][STP-PSM] [I]stp_psm_disable_by_tx_rx_density: tx cnt = 31 in the previous 3 sec
[ 110.526888] (0)[825:init]init: PropSet Error:[ro.ril.ecclist:112,911] ro.* properties may NEVER be modified once set
[ 113.473357] (0)[683:kworker/0:2][TO] 11, hotplug kworker, 100 ms, +120 ms
[ 116.855143] (1)[825:init]init: PropSet Error:[ro.ril.ecclist:112,911] ro.* properties may NEVER be modified once set
[ 119.691106] (1)[825:init]init: PropSet Error:[ro.ril.ecclist:112,911] ro.* properties may NEVER be modified once set
[ 121.756422] (2)[825:init]init: PropSet Error:[ro.ril.ecclist:112,911] ro.* properties may NEVER be modified once set
[ 122.600141] (1)[1:init]init: ofono main process (1896) killed by SEGV signal
[ 122.600227] (1)[1:init]init: ofono main process ended, respawning

I can see the crash log _usr_sbin_ofonod.0.crash in the var/crash. File appeared after I first cleaned the directory and rerun
the case so it must be coming from the incident. I don't know how to get it out of the device however. (If I try to copy the file
to the laptop, I get "libmtp error: Could not get file from device."

Syslog gives following:

Sep 5 09:20:29 ubuntu-phablet ofonod[1907]: Registered handle for channel 13: 0x10008
Sep 5 09:20:29 ubuntu-phablet ofonod[1907]: Registered handle for channel 1: 0x10009
Sep 5 09:20:37 ubuntu-phablet ofonod[1907]: mtk_radio_state_changed, slot 1: state: SIM_READY ril->ofono_online: 1
Sep 5 09:20:38 ubuntu-phablet ofonod[1907]: ril_data_reg_cb: DATA_REGISTRATION_STATE reply failure: GENERIC_FAILURE
Sep 5 09:20:51 ubuntu-phablet ofonod[1907]: mtk_radio_state_changed, slot 1: state: SIM_LOCKED_OR_ABSENT ril->ofono_online: 1

Before new start of ofono.

Ok, this is more exact log from the crash.

ofonod[3225]: src/modem.c:modem_change_state() old state: 3, new state: 1
ofonod[3225]: src/modem.c:flush_atoms()
ofonod[3225]: src/message-waiting.c:mw_remove() atom: 0x820d98
ofonod[3225]: src/gprs.c:gprs_context_unregister() 0x820b08, 0x8208e8
ofonod[3225]: src/gprs.c:gprs_context_remove() atom: 0x820b28
ofonod[3225]: drivers/rilmodem/gprs-context.c:ril_gprs_context_remove() *gc: 0x820b08
ofonod[3225]: src/gprs.c:gprs_context_unregister() 0x820ac8, 0x8208e8
ofonod[3225]: src/gprs.c:gprs_context_remove() atom: 0x820ae8
ofonod[3225]: drivers/rilmodem/gprs-context.c:ril_gprs_context_remove() *gc: 0x820ac8
ofonod[3225]: Unregistered handle for channel 1: 0x10009
ofonod[3225]: src/gprs.c:gprs_unregister() 0x8208e8
ofonod[3225]: src/network.c:__ofono_netreg_remove_status_watch() 0x800c60
ofonod[3225]: src/gprs.c:gprs_remove() atom: 0x820958
ofonod[3225]: drivers/rilmodem/gprs.c:ril_gprs_remove()
ofonod[3225]: src/call-barring.c:call_barring_remove() atom: 0x8208b0
ofonod[3225]: src/call-forwarding.c:call_forwarding_remove() atom: 0x81c0e0
ofonod[3225]: src/call-settings.c:call_settings_remove() atom: 0x8005f0
ofonod[3225]: src/ussd.c:ussd_remove() atom: 0x81e0c0
ofonod[3225]: src/sim.c:ofono_sim_remove_spn_watch() 0x800b20

Crash happens after trying to remove the SPN watch. I suspect that this might be related to MTK modems peculiar startup/shutdown sequence. It does not seem to have ofono_sim_driver_register call like rilmodem does.

I can reproduce it with just one SIM:

1) Start phone with PIN locked SIM in slot 0
2) ./enter-pin /ril_0 pin <code>
3) ./unlock-pin /ril_0 pin <wrong code> X 3

*and* the crash happens also in mako.

The reason of the crash is that after detection of locking of the SIM, this sequence of calls happen:

sim_pin_query_cb -> sim_free_main_state -> sim_spn_close. This function removes the full list of spn watches.

After this, SIM changes its state and the modem is notified, which moves the modem state to PRE_SIM. When that happens all atoms created in ONLINE state get destroyed. This includes the netreg atom (both mako and krillin), that tries to remove the watch for the spn it had, but spn_watches is NULL and ofono crashes at that moment.

This happens both in mako and krillin, but krillin has additional problems as the SIM atom is created when the modem is ONLINE while for mako that happens in PRE_SIM. Changes in the ofono core have been done to be able to address this.

The PR with a fix can be found at

https://github.com/rilmodem/ofono/pull/118

which includes the changes for both mako and krillin.

Thanks for the detailed analysis.

FYI, with the latest version ( 1.12.bzr6876+14.10.20140904-0ubuntu1 ) of ofono installed, I tried to reproduce the above scenario on mako running image #26, and I don't see the crash. It may be that the changes made to ensure that the SimManager is created earlier changes things up such that this doesn't happen on mako anymore. Can you try and reproduce it with the version of ofono that landed yesterday ( hopefully it landed in rtm this evening )?

I will try krillin tomorrow.

 I was able to reproduce this in image 235 in mako, utopic.

Note that you might be unaware of the crash due to upstart respawning ofono. Please take a look to ofono pid before and after testing this, or to the syslog. Otherwise everything seems perfectly fine.

Yes, I've seen this when I've been testing 1.12.bzr6876+14.10.20140904-0ubuntu1 when it was in silo testing phase. Monitor-ofono is also pretty clear indicator. If you see ModemAdded events with empty interfaces for same modems which were alive and well moment ago it means that they dropped down wrongly.

OK, I manged to recreate on mako running rtm image #26, not sure what I missed the last time.

I will continue the code review, and added appropriate tags to the bug.

This bug was fixed in the package ofono - 1.12.bzr6878+14.10.20140926-0ubuntu1

---------------
ofono (1.12.bzr6878+14.10.20140926-0ubuntu1) 14.09; urgency=medium

  [ Alfonso Sanchez-Beato ]
  * include, plugins/mtk.c, src/modem.c,sim.c: Fix PUK crash (LP: #1365481)
    If the SIM gets locked in particular sequence, ofono will crash
    while trying to free the list of SIM SPN watch events ( which
    have already been freed ). MTK fix is a bit more involved than
    the stanard RIL logic.

  * plugins/mtk.c,ril.c: Show emergency numbers in flight-mode (LP: #1366188)
    Modify plugin logic to create the SimManager interface even if
    no SIM is present.

  * gril, unit: fix indicator-network crash (LP: #1368675)
    RIL defines a set of network registration states for emergency
    calling that don't map directly to ofono's states. This results
    in NetworkRegistration Status not being set at all, which in
    turn crashes the indicator.

  * rilmodem/gprs.c: fix crash due to stale timer event (LP: # 1373351)
    A 5s timer is set to retry a STATUS request to RIL, however if
    FlightMode is enabled, the gprs atom is destroyed, and the pending
    timer callback has a stale gprs reference. Now the timer id is
    stored, and when the atom destroyed, the timer event is cancelled.

  * mtkmodem/radio-setttings.c: fix RadioSettings creation (LP: #1374029 )
    If the MTK modem returns a RADIO_NOT_AVAIL error in response
    to a FastDormany RIL request, the RadioSetting initialization
    callback sequence is broken, and thus the RadioSettings interface
    isn't created. This in turn prevents powerd from enabling
    FastDorancy whenever the screen is turned off, and also has
    implications for system-settings too.

  [ Tony Espy ]
  * plugins/ubuntu-apndb.c: allow MMS APNs w/out proxy (LP: #1362008)
    Prior to this change, MMS APNs w/out a proxy were skipped.
    Now APNs are skipped if message center is missing, which makes
    more sense.

  [ Ubuntu daily release ]
  * New rebuild forced

ofono (1.12.bzr6876+14.10.20140904-0ubuntu1) utopic; urgency=medium

  [ Jussi Kangas ]
  * src/gprs.c: Fix to allow MMS properties to be set (LP: #1362068)

  [ Tony Espy ]
  * rilmodem/sim.c: Fix EnterPIN logic (LP: #1363413)

  [ Ubuntu daily release ]
  * New rebuild forced
 -- Ubuntu daily release <email address hidden> Fri, 26 Sep 2014 17:34:10 +0000

Same version landed in RTM.