Bluetooth drops HFP periodically in car

robthebold · 6 May 2023 14:59

REPRODUCIBILITY: 75% (often)
OSVERSION: 4.5.0.19
HARDWARE: Sony Xperia 10 II - Dual SIM - xqau52 - xqau52 - 1.0.0.19 - aarch64
UI LANGUAGE: English (US) (user: en_US, os: en_US.utf8)
REGRESSION: yes (since: n/a - aarch64)

DESCRIPTION:

While using Bluetooth with a built-in car kit, the hands-free protocol disconnects and re-connects periodically during a trip. Calls in or out of the car are not possible when disconnected. Handset still works.

PRECONDITIONS:

I’m using built-in Bluetooth speakerphone in a BMW i3. I’ve successfully paired Xperia 10 II running sfos with car without any hiccups.

STEPS TO REPRODUCE:

Pair Bluetooth with car.
Set to connect automatically.
Start car and watch car display for phone connected status. Status will switch from connected to not connected every few minutes.

EXPECTED RESULTS:

Bluetooth HFP would remain connected untill normal disconnect - soecifically in this case after shutting down car and closing driver door, which is normal for this model.

ACTUAL RESULTS:

HFP connection drops every few minutes and re-connects again after another delay of some minutes. While disconnected, incoming calls are routed to handset and outgoing calls only possible with handset. Bluetooth appears to still be connected, but only with stereo audio profile not HFP.

MODIFICATIONS:

Patchmanager: no
OpenRepos: yes
Chum: yes
Other: none specified

ADDITIONAL INFORMATION:

I haven’t seen HFP drop during a call. Also, the media player profile appears to remain connected when HFP drops. Haven’t been able to confirm it’s really working for media or not when in this state. Same problem seems to occur with this phone in other cars (Toyota with built-in car kit) but haven’t tested as thoroughly.

Other phones (2 different iPhones) don’t seem to have same HFP dropping issue as the Sony running sfos, but I haven’t tested this as thoroughly.

I believe this is a regression since I don’t remember having problem until a few months ago. I’m not certain exactly when nor the sfos version where it worked as expected.
Device Owner User: defaultuser
Home Encryption: enabled

Pics showing bluetooth status when HFP connected and when dropped. Signal strength at top of car display also disappears when HFP droos.

the initial version of this bug report was created using Bugger 0.9.9+git4

deloptes · 7 May 2023 10:45

I am using the Xperia 10 II Dual SIM over BT with a Honda and have no issues with it. Also with other devices - no disconnects.
You could log information on the phone and see why it is disconnecting. It could be you have a bug somewhere on the car part as well or something between the two, but without logging it will be hard to say.

pherjung · 7 May 2023 10:50

Read more on this page: Collect Bluetooth Logs | Sailfish OS Documentation

robthebold · 23 May 2023 23:21

OK, I collected some logs from time the HFP connection dropped, but I don’t spot anything in the log that means something to me as to the cause. If this gives anyone a clue, I’d love to hear it. Here’s an excerpt from the time of the problem occurring (from about 30 prior to 30 secs after):

May 07 16:29:23 Xperia10II-DualSIM kernel: Freezing user space processes ... (elapsed 0.032 seconds) done.
May 07 16:29:23 Xperia10II-DualSIM kernel: OOM killer disabled.
May 07 16:29:23 Xperia10II-DualSIM kernel: Freezing remaining freezable tasks ... (elapsed 0.003 seconds) done.
May 07 16:29:23 Xperia10II-DualSIM kernel: Suspending console(s) (use no_console_suspend to debug)
May 07 16:29:23 Xperia10II-DualSIM kernel: Disabling non-boot CPUs ...
May 07 16:29:23 Xperia10II-DualSIM kernel: IRQ 2: no longer affine to CPU1
May 07 16:29:23 Xperia10II-DualSIM kernel: IRQ 7: no longer affine to CPU1
May 07 16:29:23 Xperia10II-DualSIM kernel: IRQ 20: no longer affine to CPU1
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU1: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU2: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU3: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU4: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU5: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU6: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU7: shutdown
May 07 16:29:23 Xperia10II-DualSIM kernel: suspend ns:  772969557461991        suspend cycles:   32079194273040
May 07 16:29:23 Xperia10II-DualSIM kernel: resume cycles:   32079861997336
May 07 16:29:23 Xperia10II-DualSIM kernel: Enabling non-boot CPUs ...
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu1 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU1 is up
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu2 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU2 is up
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu3 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU3 is up
May 07 16:29:23 Xperia10II-DualSIM kernel: arch_timer: CPU4: Trapping CNTVCT access
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu4 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU4 is up
May 07 16:29:23 Xperia10II-DualSIM kernel: arch_timer: CPU5: Trapping CNTVCT access
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu5 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU5 is up
May 07 16:29:23 Xperia10II-DualSIM kernel: arch_timer: CPU6: Trapping CNTVCT access
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu6 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU6 is up
May 07 16:29:23 Xperia10II-DualSIM kernel: arch_timer: CPU7: Trapping CNTVCT access
May 07 16:29:23 Xperia10II-DualSIM kernel:  cache: parent cpu7 should not be sleeping
May 07 16:29:23 Xperia10II-DualSIM kernel: CPU7 is up
May 07 16:29:23 Xperia10II-DualSIM kernel: OOM killer enabled.
May 07 16:29:23 Xperia10II-DualSIM kernel: Restarting tasks ... done.
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:23 Xperia10II-DualSIM kernel: PM: PM: suspend exit 2023-05-07 21:29:23.752651949 UTC
May 07 16:29:23 Xperia10II-DualSIM kernel: PM: suspend exit
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:23 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:23 Xperia10II-DualSIM kernel: ## mmc1: mmc_gpio_set_uim2_en: gpio=101 value=1
May 07 16:29:26 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CLCC\r
May 07 16:29:26 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:29:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:29:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:29:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+COPS?\r
May 07 16:29:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+COPS: 0,0,"T-Mobile"\r\n\r\nOK\r\n
May 07 16:29:28 Xperia10II-DualSIM kernel: PM: PM: suspend entry 2023-05-07 21:29:28.744047032 UTC
May 07 16:29:28 Xperia10II-DualSIM kernel: PM: suspend entry (deep)
May 07 16:30:27 Xperia10II-DualSIM kernel: PM: Syncing filesystems ... done.
May 07 16:30:27 Xperia10II-DualSIM kernel: Freezing user space processes ... (elapsed 0.020 seconds) done.
May 07 16:30:27 Xperia10II-DualSIM kernel: OOM killer disabled.
May 07 16:30:27 Xperia10II-DualSIM kernel: Freezing remaining freezable tasks ... (elapsed 0.003 seconds) done.
May 07 16:30:27 Xperia10II-DualSIM kernel: Suspending console(s) (use no_console_suspend to debug)
May 07 16:30:27 Xperia10II-DualSIM kernel: Disabling non-boot CPUs ...
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU1: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU2: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU3: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU4: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU5: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU6: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU7: shutdown
May 07 16:30:27 Xperia10II-DualSIM kernel: suspend ns:  772974864331017        suspend cycles:   32079963889221
May 07 16:30:27 Xperia10II-DualSIM kernel: resume cycles:   32081090786287
May 07 16:30:27 Xperia10II-DualSIM kernel: Enabling non-boot CPUs ...
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu1 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU1 is up
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu2 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU2 is up
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu3 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU3 is up
May 07 16:30:27 Xperia10II-DualSIM kernel: arch_timer: CPU4: Trapping CNTVCT access
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu4 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU4 is up
May 07 16:30:27 Xperia10II-DualSIM kernel: arch_timer: CPU5: Trapping CNTVCT access
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu5 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU5 is up
May 07 16:30:27 Xperia10II-DualSIM kernel: arch_timer: CPU6: Trapping CNTVCT access
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu6 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU6 is up
May 07 16:30:27 Xperia10II-DualSIM kernel: arch_timer: CPU7: Trapping CNTVCT access
May 07 16:30:27 Xperia10II-DualSIM kernel:  cache: parent cpu7 should not be sleeping
May 07 16:30:27 Xperia10II-DualSIM kernel: CPU7 is up
May 07 16:30:27 Xperia10II-DualSIM kernel: OOM killer enabled.
May 07 16:30:27 Xperia10II-DualSIM kernel: Restarting tasks ... done.
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CLCC\r
May 07 16:30:27 Xperia10II-DualSIM kernel: PM: PM: suspend exit 2023-05-07 21:30:27.759285865 UTC
May 07 16:30:27 Xperia10II-DualSIM kernel: PM: suspend exit
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM kernel: ## mmc1: mmc_gpio_set_uim2_en: gpio=101 value=1
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < \033\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:27 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/profile.c:ext_io_disconnected() Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: connected -> disconnected (0)
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/service.c:btd_service_unref() 0x15267920: ref=2
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: src/profile.c:ext_io_disconnected() Unable to get io data for hfp_ag: getpeername: Transport endpoint is not connected (107)
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: connected -> disconnected (0)
May 07 16:30:27 Xperia10II-DualSIM bluetoothd[14338]: src/service.c:btd_service_unref() 0x15267920: ref=2
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/profile.c:ext_confirm() incoming connect from A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/device.c:btd_device_add_uuid() device BMW i51796, uuid 0000111e-0000-1000-8000-00805f9b34fb
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/profile.c:ext_confirm() incoming connect from A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/service.c:btd_service_ref() 0x15267920: ref=3
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/profile.c:ext_confirm() hfp_ag authorizing connection from A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/device.c:btd_device_add_uuid() device BMW i51796, uuid 0000111e-0000-1000-8000-00805f9b34fb
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/profile.c:ext_auth() A0:56:B2:3B:8A:EF authorized to connect to hfp_ag
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/profile.c:ext_connect() hfp_ag connected to A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/service.c:btd_service_ref() 0x15267920: ref=3
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: disconnected -> connecting (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/profile.c:ext_confirm() hfp_ag authorizing connection from A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/profile.c:ext_auth() A0:56:B2:3B:8A:EF authorized to connect to hfp_ag
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/profile.c:ext_connect() hfp_ag connected to A0:56:B2:3B:8A:EF
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: disconnected -> connecting (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: connecting -> connected (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: src/device.c:device_profile_connected() hfp_ag Success (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/service.c:change_state() 0x15267920: device A0:56:B2:3B:8A:EF profile hfp_ag state changed: connecting -> connected (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: bluetoothd[14338]: plugins/policy.c:service_cb() Added hfp_ag reconnect 1
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: src/device.c:device_profile_connected() hfp_ag Success (0)
May 07 16:30:28 Xperia10II-DualSIM bluetoothd[14338]: plugins/policy.c:service_cb() Added hfp_ag reconnect 1
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+BRSF=47\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+BRSF: 2017\r\n\r\nOK\r\n
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND=?\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: ("service",(0,1)),("call",(0,1)),("callsetup",(0-3)),("callheld",(0-2)),("signal",(0-5)),("roam",(0,1)),("battchg",(0-5))\r\n\r\nOK\r\n
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CMER=3,0,0,1\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CHLD=?\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: SLC reached
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CHLD: (0,1,1x,2,2x,3,4)\r\n\r\nOK\r\n
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CMEE=1\r
May 07 16:30:29 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CCWA=1\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: powerkey.c: pwrkey_datapipe_keypress_event_cb(): powerkey pressed
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CLIP=1\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: powerkey.c: pwrkey_datapipe_keypress_event_cb(): powerkey released
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CSCS=?\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CSCS?\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: UNDEF -> OPEN
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: tklock.c: mce_tklock_unblank(): display state req: ON
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: modules/display.c: mdy_display_state_leave(): current display state = POWER_UP
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: mce-io.c: mce_write_number_string_to_file(): brightness: can't flush /sys/class/backlight/panel0-backlight/brightness: Invalid argument
May 07 16:30:30 Xperia10II-DualSIM lipstick[14428]: [D] unknown:0 - unsleepDisplay
May 07 16:30:30 Xperia10II-DualSIM kernel: dsi-ctrl:[_dsi_ctrl_setup_isr] [DSI_0] IRQ 228 registered
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] Before: Unblank
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+BTRH?\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:30 Xperia10II-DualSIM kernel: @@@@ panel power on @@@@
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+NREC=0\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] After: Unblank
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] start@1670884.370141750
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_resume: start
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_start_device: start
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_wait_for_ready: 09, 00, 10, 00, 00, 00, 00, 00 [0]
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_feature_settings: start
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_feature_settings: cover open, not send cmd
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_feature_settings: cover:0, glove:97, side:255, stamina:0, doze timeout:249
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_feature_settings: success
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_set_grip_type: re-init grip(0), edh:0, edg:0, lan:0
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] Change irq enabled
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_start_device: end
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_resume: end
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] end@1670884.447481708
May 07 16:30:30 Xperia10II-DualSIM kernel: somc_panel_color_manager: somc_panel_inject_crtc_overrides (788): Override: Already have original funcs! Is setup called twice??
May 07 16:30:30 Xperia10II-DualSIM kernel: somc_panel_color_manager: somc_panel_pcc_setup (886): Cannot read uv data: missing command
May 07 16:30:30 Xperia10II-DualSIM kernel: somc_panel_color_manager: somc_panel_pcc_setup (890): u,v is flashed 0.
May 07 16:30:30 Xperia10II-DualSIM kernel: somc_panel_color_manager: somc_panel_colormgr_apply_calibrations: Couldn't apply PCC calibration
May 07 16:30:30 Xperia10II-DualSIM kernel: somc_panel_color_manager: somc_panel_colormgr_apply_calibrations: Cannot send HSIC calibration
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] After: Unblank
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] start@1670884.452156130
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_resume: start
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_resume: already power on
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] sec_ts_resume: end
May 07 16:30:30 Xperia10II-DualSIM kernel: sec_ts 1-0048: [sec_input] end@1670884.452234305
May 07 16:30:30 Xperia10II-DualSIM kernel: dsi_panel_driver_oled_short_det_handler: VREG_NG interrupt!
May 07 16:30:30 Xperia10II-DualSIM mce[1666]: modules/display.c: mdy_brightness_set_level(): active brightness: -1 -> 46 (success after 1 failures)
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CMGF=0\r
May 07 16:30:30 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:31 Xperia10II-DualSIM mce[1666]: modules/display.c: mdy_display_state_enter(): current display state = ON
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist1=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:10)
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CPMS="SM","SM","ME"\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist1=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:10)
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist1=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:10)
May 07 16:30:31 Xperia10II-DualSIM droid-hal-init: processing action (ril.ecclist=*) from (/usr/libexec/droid-hybris/system/etc/init/ecclist.rc:6)
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CNMI=?\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CGSN\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIND?\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+CIND: 1,0,0,0,4,0,5\r\n\r\nOK\r\n
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CGMM\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CLCC\r
May 07 16:30:31 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CPBS=?\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIMI\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+COPS=3,0\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nOK\r\n
May 07 16:30:32 Xperia10II-DualSIM mce[1666]: tklock.c: tklock_dbus_notification_end_cb(): notification end from name=:1.3905 owner=:1.3905 pid=14428 uid=100000 gid=996 priv=1 cmd=/usr/bin/lipstick -plugin evdevtouch -plugin evdevmouse -plu
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CGMR\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CREG?\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CGMI\r
May 07 16:30:32 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: < AT+COPS?\r
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: > \r\n+COPS: 0,0,"T-Mobile"\r\n\r\nOK\r\n
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: < AT+BTRH?\r
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CREG=1\r
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CSQ\r
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CBC\r
May 07 16:30:33 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:35 Xperia10II-DualSIM mce[1666]: modules/proximity.c: mp_datapipe_set_proximity_sensor_actual(): state: OPEN -> UNDEF
May 07 16:30:37 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CPBS=?\r
May 07 16:30:37 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:40 Xperia10II-DualSIM kernel: i2c_geni 4a88000.i2c: i2c error :-107
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CPBS=?\r
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CGSN\r
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: < AT+CIMI\r
May 07 16:30:42 Xperia10II-DualSIM ofonod[9331]: Server: > \r\nERROR\r\n

deloptes · 24 May 2023 10:45

to me it looks like the phone/device is going to sleep mode and then wakes up
did you mangle the power management?

piggz · 24 May 2023 10:48

ive often wondered if there should be a wakelock for an active BT connection, just like how pulseaudio-modules-keepalive works while playing music.

robthebold · 24 May 2023 12:51

I don’t think I’d know how to mangle it . . . are there any settings which must not be set somewhere? Is my device narcoleptic?

deloptes · 24 May 2023 19:01

@piggz but I am using same Sony Xperia 10 II - Dual SIM - xqau52 with a Honda and it does not go into sleep mode. It is working very well.
I know that you are more experienced than me, can you confirm that in the log it is visible that the device goes to sleep mode?
I wonder if there is a setting in the mce-tool to change this. I am sure I have played with them on my older Xperia X.
BR

piggz · 24 May 2023 19:03

mcetool -searly prevents full sleep, and -senabled re-enables it. However, i dont think it should be happening for you.

robthebold · 6 August 2023 20:30

Updated to 4.5.0.21 and issue persists. (Didn’t see anything in changelog about it, but a guy can hope, right?)

thigg · 2 September 2023 06:48

is the issue going away when preventing sleepmode?
does anyone know if we can see in the logs when the device is sleeping?

robthebold · 4 September 2023 21:05

I tried as @piggz suggested and ran mcetool -searly as root and it doesn’t imprive the disconnect issue. HFP still drops and reconnects every few minutes.

lkraav · 5 September 2023 20:55

I’m seeing this connection loss problem happen on Citroen C5 RNEG radio, while it doesn’t happen on a Dynavin N7. Latter has A2DP audio capability, for one.

It’s definitely about the phone going to sleep, because as soon as I hit the side power button on X10 II, BT connection gets re-established.

I’m fairly certain BT connection used to work fine also in the Citroen in pre-4.5 versions, but can’t recall which one.

robthebold · 5 September 2023 20:56

That is both my recollection and my uncertainty.