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

leon · 17 August 2020 11:02

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:

Do a call
Finish the call
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.

jollausar · 16 October 2020 18:23

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!

Helge · 15 June 2021 07:54

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.

theseer · 15 December 2021 16:53

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.

carmenfdezb · 29 December 2021 16:44

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

Firefox84 · 29 December 2021 22:09

I also have this behavior, Xperia X with SFOS 4.3

espen · 30 December 2021 06:17

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.)

jovirkku · 30 December 2021 08:44

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.

JoOppen · 30 December 2021 09:29

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.

jovirkku · 30 December 2021 09:51

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

attah · 30 December 2021 10:39

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.

JoOppen · 30 December 2021 10:40

exactly that is what is happening

JoOppen · 30 December 2021 10:48

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)

silta · 30 December 2021 11:29

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

silta · 30 December 2021 22:27

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

theseer · 6 March 2022 09:55

In case that’s still relevant: I’m currently still on the Vodafone network in Germany. I have no idea whether they still have 3G up. But indeed the phone switches to 2G for the voice call and tries to reconnect to 4G aftewards.

If there’s anything I should test with Vodafone specific, we have to hurry because I’ll be switching to T-Mobile in a couple of days.

For me, it also takes at least 15 seconds to get back up and shows the “no network” error message. While it might be okay to wait a few seconds (which i’m not fully convinced of ), getting an error message is certainly not expected…

spark · 6 March 2022 22:43

Maybe I can rule out the “it’s the provider, not SailfishOS” argument:
I have a X10 and a XA2, running with the same Vodafone contract. The X10 has the “reconnection delay” issue (more than 10 sec), the XA2 has only a connection loss of less than a second after calls. Both phones with 4.3.0.15, but the problem exists much longer (at least since sailfish 4).

edit on why this is bugging me mostly:

When using apps/surfing and somebody calls me, connection is gone, even if I dismiss the call.
When a phone call gets interrupted somehow, usually both parties try to call again. But since my network is gone, I am not reachable for 10-20 sec. This has sometimes led to a cascade of unsuccessful back- and forth-call-attempts with everytime getting network interruptions again.

leon · 7 March 2022 10:21

Another sample: I use the same SIM card / Phone(X10II) / SFOS (latest). When in Germany (Vodafone), while on call the upper icons shows only the “signal strength”. When finishing the call it need 30s to show 4G again. Being outside of germany (holidays) and using also a vodafone network (roaming), the 3G icon is showed when making a call. After it the 4G icon shows up immediately. Its known that in Germany the 3G network is discommissioned.

Inte · 7 March 2022 11:49

I can confirm this behaviour on my X10ii, but I cannot confirm this on my XA2 nor my Gemini. Didn’t bother me that much though, since I expect an entirely new, VoLTE-capable network stack to be released soon anyways:-)

tortoisedoc · 17 March 2022 05:38

I had a similar issue; the phone stopped receiving calls (it would ring empty if called) and would just ring empty if you would make any call.
rebooting helped (going off-online didnt) , but man it took a day to find i wasnt reachable. Jolla get your s*it together please at least on the basics…