org.ofono.Error.Failed: Operation failed when activating context

[Sergio Schvezov]

Seen on
current build number: 102
device name: krillin
channel: ubuntu-touch/ubuntu-rtm/14.09-proposed
last update: 2014-10-13 11:09:43
version version: 102
version ubuntu: 20141013
version device: 20141009-ba11639
version custom: 1413152967

When trying to activate a context, ofono returns "org.ofono.Error.Failed: Operation failed"

I've reproduced it somewhat by sending an MMS to myself
http://paste.ubuntu.com/8553381/

I do believe this can be triggered just by an independent send actions as well when trying to activate contexts as seen with Orange.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Launchpad Janitor (janitor)]

This bug was fixed in the package nuntium - 0.1+14.10.20141013-0ubuntu1

---------------
nuntium (0.1+14.10.20141013-0ubuntu1) 14.09; urgency=low

  [ Sergio Schvezov ]
  * Hold off on retrying when ofono fails to activate a context with a
    generic failure (LP: #1380699)
 -- Ubuntu daily release <email address hidden> Mon, 13 Oct 2014 16:59:11 +0000

[Ricardo Salveti (rsalveti)]

Sergio, would you mind providing the ofono debug output when reproducing this issue?

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

The radio log (I already had a full ofono log from Sergio). This can be obtained using

/system/bin/logcat -b radio

while the error is being produced.

[Sergio Schvezov (sergiusens)]

syslog ^ and logcat for when the error occurs

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

Analysis of the radio log shows CME error 3350 is returned when trying to activate the context:

D/use-Rlog/RLOG-AT( 1961): AT+CGACT=1,2
...
D/use-Rlog/RLOG-AT( 1961): +CME ERROR: 3350

This error is not defined in TS 27.007, it looks MTK-specific.

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

I can easily reproduce the 3350 error code when sending to myself an MMS when technology is EDGE (2G). However, it does not happen when technology is 3G. It might be caused by trying to activate too fast a context after having just received an SMS (the MMS push notification). The SDCCH GSM channel is shared by all cell mobiles, and it is used for call set-up and SMS, so maybe we cannot use it right at that moment, as we have just used it for rx the SMS. But this is speculation until we find out the exact meaning of the code.

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

Logs from Zygmunt in comment #25 in https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/1371032/ support the hypothesis exposed in comment #8.

In the logs, the technology is edge:

    [ org.ofono.ConnectionManager ]
        Attached = 1
        Suspended = 0
        Bearer = edge
        Powered = 1
        RoamingAllowed = 0

And it is in reception of MMS:

2014/10/09 15:35:56 Received ReceiveNotification() method call from 99974
2014/10/09 15:35:56 Push data
00000000 00 06 07 be af 84 8d f0 b4 81 8c 82 98 41 42 68 |.............ABh|
00000010 7a 4e 74 67 49 59 51 66 31 72 78 4e 63 32 00 8d |zNtgIYQf1rxNc2..|
00000020 92 89 18 80 2b 33 34 36 32 32 30 33 32 32 37 30 |....+34622032270|
00000030 2f 54 59 50 45 3d 50 4c 4d 4e 00 86 81 8a 80 8e |/TYPE=PLMN......|
00000040 02 82 58 88 05 81 03 03 f4 7f 83 68 74 74 70 3a |..X........http:|
00000050 2f 2f 6d 6d 73 63 36 31 3a 31 30 30 32 31 2f 6d |//mmsc61:10021/m|
00000060 6d 73 63 2f 36 5f 31 3f 41 42 68 7a 4e 74 67 49 |msc/6_1?ABhzNtgI|
00000070 59 51 66 31 72 78 4e 63 32 00 |YQf1rxNc2.|
2014/10/09 15:35:56 Trying to set Active property to true for context on true /ril_0/context2
2014/10/09 15:35:56 Cannot set Activate to true (try 1/3) interface on /ril_0/context2: org.ofono.Error.Failed: Operation failed
2014/10/09 15:35:56 Cannot set Activate to true (try 2/3) interface on /ril_0/context2: org.ofono.Error.Failed: Operation failed
2014/10/09 15:35:56 Cannot set Activate to true (try 3/3) interface on /ril_0/context2: org.ofono.Error.Failed: Operation failed

So it might be possible that we cannot immediately grab again the GSM control channel after the SMS reception.

[Launchpad Janitor (janitor)]

This bug was fixed in the package nuntium - 0.1+14.10.20141013-0ubuntu1

---------------
nuntium (0.1+14.10.20141013-0ubuntu1) 14.09; urgency=low

  [ Sergio Schvezov ]
  * Hold off on retrying when ofono fails to activate a context with a
    generic failure (LP: #1380699)
 -- Ubuntu daily release <email address hidden> Mon, 13 Oct 2014 16:59:11 +0000

[Tony Espy (awe)]

Changed the ofono task to Incomplete as we're awaiting a response from MTK regarding the modem's behavior.

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

This is the response from MTK:

<<
MTK feedback this question as bellow:
In your current version, error:3350 represents SM_LOCAL_REJECT_ACT_REQ_DUE_TO_GPRS_SUSPENDED.
The cause of this error code may be MM has some activity, when SM to activated. So suspend (ex, LU, RAU).
The error specific code cause also needs to further analysis based on log.

SM refers to the Session Management. MM refers to the Mobility Management.
Can be understood as the mobile phone trying to PDP activation, at the same time mobile phone need location update or location registration, so be suspended.
>>

It is worth noting that this is a 2G specific error code. This confirms that the error is due to lack of radio resources. Probably, after having just received the SMS we are not allowed due to limitations of GSM to immediately attach to GPRS: we need to wait for a slot in the control channel, or something similar. It can be argued that the modem FW should wait until it is able to activate the context, and then it is a modem bug, but it looks difficult to convince MTK of this.

In my opinion the retry logic in nuntium is a correct way to handle this, as we always need to do retries as unexpected things (like this, or others) can happen.

[qing-liu (qing-liu)]

Dear Alfonso,
Sorry I refer to this case so late.And I have to understand how the bug happen. Could you reproduce this bug in kriilin android device?
And catch the mtklog. Because if we want to know more about this error, we need MTK support. And MTK will need the modem log which the mtk log to analyze this bug. Thanks!

[Tony Espy (awe)]

As the nuntium workaround has been released, and the issue itself has been verified to be caused by the rild implementation, I'm changing the status of the ofono task to 'WontFix'. If there are any objections to this, please feel free to re-open.

[zubozrout (zubozrout)]

Hello,
I am just getting this on devel-proposed:
./activate-context → Error activating /ril_0/context1: org.ofono.Error.Failed: Operation failed
and it led me right here.

I am running Nexus 7 deb (LTE), but I don't think it is a device specific issue. I can see my network provider, I have it's signal so I am connected to the network but I can't use mobile data, although sending SMS works.

Does anyone else experience that? Thank you.