Cellular/4G down after voice call (XperiaX/3.3.0.16 -- Xperia10ii/4.3.0.12)

REPRODUCIBILITY: 100%
BUILD ID: 3.3.0.16
HARDWARE: Xperia X
UI LANGUAGE: DE
REGRESSION: Yes

DESCRIPTION:

I am not sure when it starts (before 3.3 or 3.2) but every time after doing a voice call over cellular after finishing the call, the cellular stack went down (the icons in the top right corner for “data”, Gtype (4G) and signal are gone (signal icon are striped indicating not connected at all)).
Provider: Vodafone DE

PRECONDITIONS:

only confirmed on Xperia 10 (the only device here)

STEPS TO REPRODUCE:

  1. Do a call
  2. Finish the call
  3. Try a second call right away.

EXPECTED RESULT:

Doing a second call right away without waiting for the software stack being ready.

ACTUAL RESULT:

I must wait until the cellular network is connected again to do a second call.

ADDITIONAL INFORMATION:

Here some journal logs while this happend:

Aug 17 12:44:56 Sailfish invoker[20648]: WARNING: An inactive plugin is misbehaving - tried to show a window!
Aug 17 12:44:56 Sailfish invoker[20648]: WARNING: requestActivate() called for  QQuickView(0xa78390)  which has Qt::WindowDoesNotAcceptFocus set.
Aug 17 12:44:57 Sailfish [4990]: [W] unknown:0 - void TelepathyProvider::onHandlerInvalidated(const QString&, const QString&) Handler invalidated: org.freedesktop.Telepathy.Error.Terminated: Release By User
Aug 17 12:44:57 Sailfish [4990]: [D] unknown:0 - "Telepathy Handler Invalidated: org.freedesktop.Telepathy.Error.Terminated - Release By User"
Aug 17 12:44:57 Sailfish tart[20665]: [W] updateAction:205 - instance was empty
Aug 17 12:44:57 Sailfish tart[20665]: [W] updateAction:205 - instance was empty
Aug 17 12:44:57 Sailfish lipstick[20251]: [D] onDestruction:267 - coverActionIndicators destroyed voicecall-ui.desktop
Aug 17 12:44:57 Sailfish mce[2027]: tklock.c: tklock_dbus_notification_beg_cb(): notification begin from name=:1.1439 owner=:1.1439 pid=20251 uid=100000 gid=999 priv=1 cmd=/usr/bin/lipstick -plugin evdevtouch -plugin evdevkeyboard:k
Aug 17 12:44:57 Sailfish mce[2027]: tklock.c: tklock_datapipe_uiexception_type_cb(): uiexception_type = none -> notif
Aug 17 12:44:57 Sailfish tart[20665]: [W] unknown:0 - InitManagerJob Error: Job was deleted before finished!
Aug 17 12:44:57 Sailfish lipstick[20251]: [D] onCompleted:263 - coverActionIndicators created voicecall-ui.desktop
Aug 17 12:44:59 Sailfish rmt_storage:INFO:rmt_storage_rw_iovec_cb: Write iovec request received for /boot/modem_fs1
Aug 17 12:44:59 Sailfish rmt_storage:INFO:rmt_storage_client_thread: Calling Write [offset=0, size=2097152]for /boot/modem_fs1!
Aug 17 12:44:59 Sailfish rmt_storage:INFO:rmt_storage_client_thread: Done Write (bytes = 2097152) for /boot/modem_fs1!
Aug 17 12:45:03 Sailfish mce[2027]: tklock.c: tklock_datapipe_uiexception_type_cb(): uiexception_type = notif -> none
Aug 17 12:45:08 Sailfish mce[2027]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: OPEN -> UNDEF
Aug 17 12:45:15 Sailfish connmand[4635]: [ofono] ERROR! Timeout was reached
Aug 17 12:45:16 Sailfish ofonod[2968]: data reg changed 1 -> 0 (unregistered), attached 0
Aug 17 12:45:17 Sailfish droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
Aug 17 12:45:17 Sailfish droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
Aug 17 12:45:17 Sailfish kernel: R0: [netmgrd][29517720201543] [12:45:17.581545]  wlan: [3824:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:17 Sailfish mce[2027]: tklock.c: tklock_datapipe_uiexception_type_cb(): uiexception_type = none -> notif
Aug 17 12:45:17 Sailfish droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
Aug 17 12:45:17 Sailfish kernel: R0: [soft_irq][29517722406835] [12:45:17.696389]  wlan: [0:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:17 Sailfish ofonod[2968]: data reg changed 0 -> 1 (registered), attached 1
Aug 17 12:45:17 Sailfish kernel: R0: [ip][29517725587563] [12:45:17.862036]  wlan: [29846:E :HDD] __wlan_hdd_ipv4_changed: 926: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish kernel: HTB: quantum of class 10001 is big. Consider r2q change.
Aug 17 12:45:18 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:18 Sailfish ofonod[2968]: setting up data call
Aug 17 12:45:18 Sailfish mce[2027]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: UNDEF -> OPEN
Aug 17 12:45:18 Sailfish kernel: R0: [ip][29517730729801] [12:45:18.129844]  wlan: [29891:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish kernel: R0: [soft_irq][29517730838655] [12:45:18.135513]  wlan: [0:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish mce[2027]: tklock.c: tklock_dbus_notification_beg_cb(): notification begin from name=:1.1439 owner=:1.1439 pid=20251 uid=100000 gid=999 priv=1 cmd=/usr/bin/lipstick -plugin evdevtouch -plugin evdevkeyboard:k
Aug 17 12:45:18 Sailfish ofonod[2968]: Deactivating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Clearing active context
Aug 17 12:45:18 Sailfish kernel: R0: [ofonod][29517737193235] [12:45:18.466460]  wlan: [2968:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish kernel: R0: [ofonod][29517737194243] [12:45:18.466512]  wlan: [2968:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish ofonod[2968]: Deactivated data call
Aug 17 12:45:18 Sailfish connmand[4635]: Failed to connect to server 2a01:0860:0000:0300:0000:0000:0000:0053
Aug 17 12:45:18 Sailfish connmand[4635]: Failed to connect to server 2a01:0860:0000:0300:0000:0000:0000:0153
Aug 17 12:45:18 Sailfish kernel: R0: [connmand][29517737780442] [12:45:18.497041]  wlan: [4635:E :HDD] __wlan_hdd_ipv4_changed: 926: Adapter context is invalid 0000000000000000
Aug 17 12:45:18 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:18 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Unexpected data call status 4106
Aug 17 12:45:18 Sailfish connmand[4635]: [ofono] ERROR! GDBus.Error:org.ofono.Error.Failed: Operation failed
Aug 17 12:45:18 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:18 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Unexpected data call status 4106
Aug 17 12:45:18 Sailfish connmand[4635]: [ofono] ERROR! GDBus.Error:org.ofono.Error.Failed: Operation failed
Aug 17 12:45:18 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:18 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Unexpected data call status 4106
Aug 17 12:45:18 Sailfish connmand[4635]: [ofono] ERROR! GDBus.Error:org.ofono.Error.Failed: Operation failed
Aug 17 12:45:18 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:18 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Unexpected data call status 4106
Aug 17 12:45:18 Sailfish connmand[4635]: [ofono] ERROR! GDBus.Error:org.ofono.Error.Failed: Operation failed
Aug 17 12:45:18 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:18 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:18 Sailfish ofonod[2968]: Unexpected data call status 4106
Aug 17 12:45:18 Sailfish connmand[4635]: [ofono] ERROR! GDBus.Error:org.ofono.Error.Failed: Operation failed
Aug 17 12:45:19 Sailfish connmand[4635]: Skipping disconnect of /ril_0, network is connecting.
Aug 17 12:45:19 Sailfish ofonod[2968]: Activating context: 1
Aug 17 12:45:19 Sailfish kernel: R0: [ip][29517756953355] [12:45:19.495567]  wlan: [29927:E :HDD] __wlan_hdd_ipv4_changed: 926: Adapter context is invalid 0000000000000000
Aug 17 12:45:19 Sailfish kernel: HTB: quantum of class 10001 is big. Consider r2q change.
Aug 17 12:45:19 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:19 Sailfish ofonod[2968]: setting up data call
Aug 17 12:45:19 Sailfish kernel: R0: [connmand][29517762395637] [12:45:19.779001]  wlan: [4635:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:19 Sailfish kernel: R0: [soft_irq][29517762480904] [12:45:19.783442]  wlan: [0:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:19 Sailfish kernel: R0: [ip][29517763048728] [12:45:19.813014]  wlan: [29936:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:19 Sailfish kernel: R0: [soft_irq][29517764466941] [12:45:19.886875]  wlan: [0:E :HDD] __wlan_hdd_ipv6_changed: 232: Adapter context is invalid 0000000000000000
Aug 17 12:45:20 Sailfish connmand[4635]: ntp: adjust (slew): +0.158213 sec
Aug 17 12:45:20 Sailfish kernel: ipa ipa_inc_acquire_wakelock:3494 client enum 1 mask already set. ref cnt = 6
Aug 17 12:45:21 Sailfish systemd[4830]: Unknown permission start for class system
Aug 17 12:45:21 Sailfish systemd[4830]: Unknown permission start for class system
Aug 17 12:45:21 Sailfish connmand[4635]: ntp: adjust (slew): +0.008941 sec
Aug 17 12:45:22 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:23 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:24 Sailfish mce[2027]: tklock.c: tklock_dbus_notification_beg_cb(): notification begin from name=:1.1439 owner=:1.1439 pid=20251 uid=100000 gid=999 priv=1 cmd=/usr/bin/lipstick -plugin evdevtouch -plugin evdevkeyboard:k
Aug 17 12:45:27 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:27 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:28 Sailfish healthd: battery l=69 v=3945 t=34.0 h=2 st=2 c=26 chg=u
Aug 17 12:45:28 Sailfish kernel: R0: [power@1.3-servi][29517922291302] [12:45:28.107780]  wlan: [3163:I :HDD] wlan_hdd_modules_are_enabled: 851: Modules not enabled, Present status: 3
Aug 17 12:45:28 Sailfish kernel: R0: [power@1.3-servi][29517922938366] [12:45:28.141483]  wlan: [3163:I :HDD] wlan_hdd_modules_are_enabled: 851: Modules not enabled, Present status: 3
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:29 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:30 Sailfish mce[2027]: tklock.c: tklock_datapipe_uiexception_type_cb(): uiexception_type = notif -> none
Aug 17 12:45:34 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:34 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:35 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:35 Sailfish mce[2027]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: OPEN -> UNDEF
Aug 17 12:45:35 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:48 Sailfish healthd: battery l=69 v=3978 t=34.0 h=2 st=2 c=-260 chg=u

Aug 17 12:45:50 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:50 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.

Aug 17 12:45:50 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:50 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.

Aug 17 12:45:51 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
Aug 17 12:45:51 Sailfish kernel: HTB: quantum of class 10010 is big. Consider r2q change.
4 Likes

Hi Xperia 10 dual sim user here, 3.3 and 3.4.
I can confirm this - happens sometimes, not always.
Also vodafone.de on sim1 and congstar on sim2.
The problem for me is not the reconnecting right afterwards, but the time it takes to connect. Sometimes up to 60 seconds!
Same thing when going out of flight mode, sometimes it happens within seconds, sometimes more than 60 secs.
Same behaviour when switching the mobile or voice SIM. When both have been connected and i switch over to the other sim, one of the two (or both) disconnect and take the time to connect again…
Very annoing!

1 Like

I can confirm this behaviour on single sim Xperia 10 with o2-de. I noticed it on 4.1.0.24 but it could have been started on earlier releases.

I’m seeing this very behaviour on my Xperia X 10 ii - Dual Sim with SFOS 4.3.0.12. Also having a vodafone SIM in Slot 1, currently no SIM in slot 2 as I use it for an SDCard.

To make matters worse, I sometimes have that also when trying to place a call. It claims “no network” when calling even though right before it showed all is fine. When “hanging up”, the aforementioned behaviour can be also observed. Not sure if that is in any way related.

I have the same issue with my Xperia 10 II and 4.3 SFOS

I also have this behavior, Xperia X with SFOS 4.3

This drop of connection at ‘hanging up’ is a very annoying behavior also of my Xperia 10 ii Dual SIM (XQ-AU52) with 4.3.0.12. Telia SIM in Slot 1, no SIM in slot 2.

My general impression is that lost connections during calls and ‘no network’ messages occurs quite more often than before. I use my phone a lot in my car, though, so this may be another issue of problems with moving between base stations. (I’ve for years travelled the same routes with SFOS on BT in my cars, and do think that problems with network connections is more pronounced with current version of phone/OS. Can’t provide any hard statistics on this, though.)

1 Like

Thank you for your reports.

The original report had this line:
“I must wait until the cellular network is connected again to do a second call.”

The three of you have the latest OS version 4.3.0 and a recent Xperia model 10ii.
How long is this delay for you?
Does your operator still have their 3G network alive?

I am particularly interested in espen’s reply as he is using Telia. I have Telia Finland. When I get “call ended” I am able to immediately place the next call from the call history, so in about 5 seconds. I could not do it any faster, i.e., I do not see any delay there at all.

I have the same problem. Minimum waiting time for network-reconnection between two calls is about 40 seconds, often longer. SIM is congstar (t-mobile Germany), phone is Xperia 10 ii with SFOS 4.3. My impression is that the problem became serious when t-mobile canceled 3G.

1 Like

Phone on 4G. Call made/received => must connect to 2G. Call ended => phone returns to 4G.

I’m not at all convinced this is a Sailfish issue… Where you get redirected during and after a call is up to the operator. For me, right now, on Telia SE it took maybe 4-5 seconds after the call finished.

One reason i can see for it to take 10s of seconds is a misconfigured network, or that you are just unlucky with the coverage overlap. I.e. you get redirected to the wrong frequency, the phone gives up on it and scans again from scratch.

Possibly this could tell you if that is the case: Cellular protocol logging with Sailfish OS
(no, i don’t even remember how to start it any more)
Then the EARFCN(s) in E-UTRAN Individual Priority Parameters in the GSM Channel Release would be different from the frequency where you eventually end up.

exactly that is what is happening

Indeed, I am not sure whether this is SFOS specific or not. However, I believe that VoLTE makes a big difference because with VoLTE, falling back to 2G should be obsolete, if I am not mistaken. Most other phones use VoLTE so that may be a reason why Android and iOS user do not notice this problem. Also I observed that reconnection takes longer in larger cities with many providers so it could be a network protocol issue (but this is just a wild guess)

Of course, but the time from ‘Call ended => phone returns to 4G’ is much too long, minimum 20 seconds, as I described in my bug report

In my case it was before t-mobile cancelled 3G. I observed it on my Xperia 10 II from the first available SFOS version.