Project

General

Profile

Actions

Issue #1954

open

Add support for the I9300 modem

Added by Denis 'GNUtoo' Carikli about 5 years ago. Updated almost 3 years ago.

Status:
In Progress
Priority:
Normal
Category:
Telephony and mobile data
Target version:
Start date:
08/25/2020
Due date:
% Done:

33%

Estimated time:
(Total: 0.00 h)
Resolution:
Device:
Galaxy S 3 (I9300)
Grant:
Porting Replicant to Android 9 (NLnet Foundation)
Type of work:
C programming

Subtasks 12 (8 open4 closed)

Issue #2115: Port libsamsung-ril to Replicant 11NewDenis 'GNUtoo' Carikli08/25/2020

Actions
Issue #2116: Add support for the Replicant 11 kernel in libsamsung-ipcNewDenis 'GNUtoo' Carikli08/25/2020

Actions
Issue #2117: Add SRS support in Replicant 11NewDenis 'GNUtoo' Carikli08/25/2020

Actions
Issue #2118: Finish cleaning up the Linux modem driver, fix bugs, and import it in the Replicant 11 kernelNewDenis 'GNUtoo' Carikli08/25/2020

Actions
Issue #2119: Add support for the Replicant 11 kernel modem driver in libsamsung-ipc, possibly in a replicant-11 branchNewDenis 'GNUtoo' Carikli08/25/2020

Actions
Issue #2215: Integrate libsamsung-ipc and libsamsung-ril in Replicant >= 9ClosedDenis 'GNUtoo' Carikli02/16/2021

Actions
Issue #2217: Implement the GPIO power management API in the kernel as well?Rejected02/24/2021

Actions
Issue #2218: Investigate how to push modem firmware loading + on/off in the kernelNew02/24/2021

Actions
Issue #2231: Fix rare kernel crash with modem driverRejectedDenis 'GNUtoo' Carikli03/14/2021

Actions
Issue #2232: Check if the EFS works fineNewDenis 'GNUtoo' Carikli03/14/2021

Actions
Issue #2233: Integrate rild in the HIDL / ManifestNewDenis 'GNUtoo' Carikli03/14/2021

Actions
Issue #2234: ipc-modem doesn't call with the replicant 11 kernelClosedDenis 'GNUtoo' Carikli03/17/2021

Actions
Actions #1

Updated by Denis 'GNUtoo' Carikli about 5 years ago

This enables to track the progress in more details and not spam the PortingToAndroid9 wiki page.

Actions #2

Updated by Denis 'GNUtoo' Carikli about 5 years ago

Here's how the log looks on Replicant 6.0:

 D use-Rlog/RLOG-RIL-IPC: Starting i9300 modem boot
 D use-Rlog/RLOG-RIL-IPC: Opened modem image device
 D use-Rlog/RLOG-RIL-IPC: Mapped modem image data to memory
 D use-Rlog/RLOG-RIL-IPC: Opened modem boot device
 D use-Rlog/RLOG-RIL-IPC: Opened modem link device
 D use-Rlog/RLOG-RIL-IPC: Turned the modem off
 D use-Rlog/RLOG-RIL-IPC: Turned the modem on
 D use-Rlog/RLOG-RIL-IPC: Waited for link connected
 D use-Rlog/RLOG-RIL-IPC: Wrote ATAT in ASCII
 D use-Rlog/RLOG-RIL-IPC: Reading boot ACK failed
 D use-Rlog/RLOG-RIL-IPC: Sending XMM626 HSIC PSI failed
 E use-Rlog/RLOG-RIL-IPC: Booting IPC FMT client failed
 E use-Rlog/RLOG-RIL: Opening IPC FMT client failed
 D use-Rlog/RLOG-RIL: Closed IPC FMT client
 D use-Rlog/RLOG-RIL-IPC: Starting i9300 modem boot
 D use-Rlog/RLOG-RIL-IPC: Opened modem image device
 D use-Rlog/RLOG-RIL-IPC: Mapped modem image data to memory
 D use-Rlog/RLOG-RIL-IPC: Opened modem boot device
 D use-Rlog/RLOG-RIL-IPC: Opened modem link device
 D use-Rlog/RLOG-RIL-IPC: Turned the modem off
 D use-Rlog/RLOG-RIL-IPC: Turned the modem on
 D use-Rlog/RLOG-RIL-IPC: Waited for link connected
 D use-Rlog/RLOG-RIL-IPC: Wrote ATAT in ASCII
 D use-Rlog/RLOG-RIL-IPC: Read chip id (0x16)
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI header
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI, CRC is 0xc8
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI CRC (0xc8)
 D use-Rlog/RLOG-RIL-IPC: Read PSI CRC ACK
 D use-Rlog/RLOG-RIL-IPC: Read PSI ACK
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC PSI
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL size
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL, CRC is 0xb5
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL CRC (0xb5)
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC EBL
 D use-Rlog/RLOG-RIL-IPC: Read port config
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC port config
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC SEC start
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC firmware
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data path
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data md5 path
 D use-Rlog/RLOG-RIL-IPC: Calculated nv_data md5: 50e04bd1ae13445977f3aec356ada08d
 D use-Rlog/RLOG-RIL-IPC: Read nv_data md5: 50e04bd1ae13445977f3aec356ada08d
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data backup path
 D use-Rlog/RLOG-RIL-IPC: Loaded nv_data
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC nv_data
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC HW reset
 D use-Rlog/RLOG-RIL-IPC: Waiting for host wake failed
 D use-Rlog/RLOG-RIL-IPC: Waited for host wake
 D use-Rlog/RLOG-RIL-IPC: Waited for link connected
 D use-Rlog/RLOG-RIL: Opened IPC FMT client
 D use-Rlog/RLOG-RIL-IPC: 
 D use-Rlog/RLOG-RIL-IPC: xmm626_sec_modem_fmt_recv: Received FMT message
 D use-Rlog/RLOG-RIL-IPC: xmm626_sec_modem_fmt_recv: Message: aseq=0xff, command=IPC_PWR_PHONE_PWR_UP, type=IPC_TYPE_NOTI, size=0
 D use-Rlog/RLOG-RIL: Updating RIL radio state to 0
 [...]

On Replicant 9.0 we have:


 # adb shell
 # /system/bin/xmm6262_boot0.sh 
 # exit
 # adb logcat -b radio
 [...] D use-Rlog/RLOG-RIL-IPC: Starting generic modem boot
 D use-Rlog/RLOG-RIL-IPC: Opened modem image device
 D use-Rlog/RLOG-RIL-IPC: Mapped modem image data to memory
 D use-Rlog/RLOG-RIL-IPC: Turned the modem off
 D use-Rlog/RLOG-RIL-IPC: Turned the modem on
 D use-Rlog/RLOG-RIL-IPC: Opened modem boot device
 D use-Rlog/RLOG-RIL-IPC: Wrote ATAT in ASCII
 D use-Rlog/RLOG-RIL-IPC: Read chip id (0x16)
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI header
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI, CRC is 0xc8
 D use-Rlog/RLOG-RIL-IPC: Wrote PSI CRC (0xc8)
 D use-Rlog/RLOG-RIL-IPC: Read PSI CRC ACK
 D use-Rlog/RLOG-RIL-IPC: Read PSI ACK
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC PSI
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL size
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL, CRC is 0xb5
 D use-Rlog/RLOG-RIL-IPC: Wrote EBL CRC (0xb5)
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC EBL
 D use-Rlog/RLOG-RIL-IPC: Read port config
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC port config
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC SEC start
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC firmware
 D use-Rlog/RLOG-RIL-IPC: ipc_nv_data_path_check: nv_data path: /efs/nv_data.bin
 D use-Rlog/RLOG-RIL-IPC: ipc_nv_data_path_check: nv_data size: 2097152
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data path
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data md5 path
 D use-Rlog/RLOG-RIL-IPC: Calculated nv_data md5: 50e04bd1ae13445977f3aec356ada08d
 D use-Rlog/RLOG-RIL-IPC: Read nv_data md5: 50e04bd1ae13445977f3aec356ada08d
 D use-Rlog/RLOG-RIL-IPC: Checked nv_data backup path
 D use-Rlog/RLOG-RIL-IPC: Loaded nv_data
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC nv_data
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC SEC end
 D use-Rlog/RLOG-RIL-IPC: Sent XMM626 HSIC HW reset
 D use-Rlog/RLOG-RIL-IPC: Waited for host wake
 D use-Rlog/RLOG-RIL-IPC: Waited for link connected
 E use-Rlog/RLOG-RIL-IPC: Opening IPC FMT client failed
 E use-Rlog/RLOG-RIL: Opening IPC FMT client failed
 [...]

Under Parabola with the same kernel and ipc-test we get a similar log.

After some investigations, loading the modem firmware has been validated.

However after the firmware has been loaded, the software stack is supposed to reset the HSIC link and after some messing with the modem GPIOs through sysfs, new USB descriptors are supposed to appear. Right now they don't appear.

Actions #3

Updated by Denis 'GNUtoo' Carikli about 5 years ago

TODO:
  • Investigate how the XMM626_SEC_HOSTWAKE_PATH is supposed to work. I also modified the driver to remove the IRQ related to that as it was conflicting with other uses of that GPIO.
  • Investigate what exactly the other modem sysfs nodes are supposed to do.
  • Investigate more the EHCI reset hack

Also note that this modem code has not been validated either on older kernel versions.

Actions #4

Updated by Denis 'GNUtoo' Carikli about 5 years ago

The modem finally booted:

[root@u-boot-i9300 ~]# ipc-test 
ENTER ipc_client_create
ipc_client_create: IPC_CLIENT_TYPE_FMT
ipc_client_create: complete
ipc_client_create: return client
main: ipc_client_create(IPC_CLIENT_TYPE_FMT) => 0
main: ipc_client_log_callback_register(client, log_callback, NULL) => 0
main: ipc_client_data_create(client) => 0
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Starting generic modem boot
[ipc] Opened modem image device
[ipc] Mapped modem image data to memory
[ipc] Turned the modem off
generic_boot: xmm626_sec_modem_power(NULL, 1) = 0
generic_boot: xmm626_sec_modem_hci_power(1) = 0
[ipc] Turned the modem on
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Opened modem boot device
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Wrote ATAT in ASCII
[ipc] Read chip id (0x16)
[ipc] Wrote PSI header
[ipc] Wrote PSI, CRC is 0xc8
[ipc] Wrote PSI CRC (0xc8)
[ipc] Read PSI CRC ACK
[ipc] Read PSI ACK
[ipc] Sent XMM626 HSIC PSI
[ipc] Wrote EBL size
[ipc] Wrote EBL, CRC is 0xb5
[ipc] Wrote EBL CRC (0xb5)
[ipc] Sent XMM626 HSIC EBL
[ipc] Read port config
[ipc] Sent XMM626 HSIC port config
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Sent XMM626 HSIC SEC start
[ipc] Sent XMM626 HSIC firmware
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] ipc_nv_data_path_check: nv_data path: /efs/nv_data.bin
[ipc] ipc_nv_data_path_check: nv_data size: 2097152
[ipc] Checked nv_data path
[ipc] Checked nv_data md5 path
[ipc] Calculated nv_data md5: 50e04bd1ae13445977f3aec356ada08d
[ipc] Read nv_data md5: 50e04bd1ae13445977f3aec356ada08d
[ipc] Checked nv_data backup path
[ipc] Loaded nv_data
[ipc] Sent XMM626 HSIC nv_data
[ipc] Sent XMM626 HSIC SEC end
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Sent XMM626 HSIC HW reset
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
xmm626_sec_modem_link_get_hostwake_wait: i=0 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=1 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=2 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=3 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=4 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=5 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=6 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=7 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=8 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=9 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
[ipc] Waited for host wake
Bus 001 Device 002: ID 058b:0041 Infineon Technologies Flash Loader utility
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] Turned off the modem
xmm626_sec_modem_link_get_hostwake_wait: i=0 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=1 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=2 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=3 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=4 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=5 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=6 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=7 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=8 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
xmm626_sec_modem_link_get_hostwake_wait: i=9 read(/sys/devices/platform/xmm6262/hostwake) => status: 0
[ipc] Waited for host wake
[ipc] Turned the modem on
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[ipc] generic_boot complete
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[root@u-boot-i9300 ~]# lsusb
Bus 001 Device 002: ID 1519:0020 Comneon HSIC Device
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

And the corresponding dmesg:

[root@u-boot-i9300 ~]# dmesg
[   26.085293] max77693-muic max77693-muic: external connector is attached(chg_type:0x1, prev_chg_type:0x1)
[   26.094458] max77693-muic max77693-muic: CONTROL1 : 0x09, CONTROL2 : 0x04, state : attached
[   31.270306] gpiohack xmm6262: new state: 0
[   31.273001] exynos-ehci 12580000.ehci: Powering off EHCI
[   31.280444] exynos-ehci 12580000.ehci: remove, state 1
[   31.284112] usb usb1: USB disconnect, device number 1
[   31.295131] exynos-ehci 12580000.ehci: USB bus 1 deregistered
[   31.350218] gpiohack xmm6262: link active? 0
[   31.353441] gpiohack xmm6262: new state: 1
[   31.625132] gpiohack xmm6262: pda active => 1
[   31.628647] exynos-ehci 12580000.ehci: Powering on EHCI
[   31.633557] exynos-ehci 12580000.ehci: EHCI Host Controller
[   31.639063] exynos-ehci 12580000.ehci: new USB bus registered, assigned bus number 1
[   31.647179] exynos-ehci 12580000.ehci: irq 58, io mem 0x12580000
[   31.674509] exynos-ehci 12580000.ehci: USB 2.0 started, EHCI 1.00
[   31.679459] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.03
[   31.687484] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   31.694655] usb usb1: Product: EHCI Host Controller
[   31.699461] usb usb1: Manufacturer: Linux 5.3.0-rc8+ ehci_hcd
[   31.705222] usb usb1: SerialNumber: 12580000.ehci
[   31.712308] hub 1-0:1.0: USB hub found
[   31.714653] hub 1-0:1.0: 3 ports detected
[   31.770222] gpiohack xmm6262: link active? 1
[   32.084589] usb 1-2: new high-speed USB device number 2 using exynos-ehci
[   32.286228] usb 1-2: config 1 interface 0 altsetting 0 endpoint 0x81 has an invalid bInterval 255, changing to 11
[   32.295155] usb 1-2: New USB device found, idVendor=058b, idProduct=0041, bcdDevice= 0.00
[   32.303184] usb 1-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   32.317235] xmm6262_boot 1-2:1.0: ENTER xmm6262_probe
[   32.321529] xmm6262_boot 1-2:1.0: Loaded XMM6262 boot serial device!
[   32.325300] ENTER xmm6262_boot_open
[   32.332038] xmm6262_boot 1-2:1.0: xmm6262_boot_open: got dev
[   32.336375] xmm6262_boot 1-2:1.0: xmm6262_boot_open: return 0;
[   39.166477] xmm6262_boot 1-2:1.0: nonzero bulk read status: -71
[   39.228235] gpiohack xmm6262: phone_active: cp_reset=1, phone_active=1, cp_dump=0
[   39.234260] gpiohack xmm6262: BOOTING
[   44.425149] exynos-ehci 12580000.ehci: Powering off EHCI
[   44.429111] exynos-ehci 12580000.ehci: remove, state 1
[   44.434106] usb usb1: USB disconnect, device number 1
[   44.442866] usb 1-2: USB disconnect, device number 2
[   44.451825] exynos-ehci 12580000.ehci: USB bus 1 deregistered
[   44.508775] gpiohack xmm6262: link active? 0
[   49.609709] gpiohack xmm6262: pda active => 1
[   49.612682] exynos-ehci 12580000.ehci: Powering on EHCI
[   49.620936] exynos-ehci 12580000.ehci: EHCI Host Controller
[   49.625160] exynos-ehci 12580000.ehci: new USB bus registered, assigned bus number 1
[   49.633296] exynos-ehci 12580000.ehci: irq 58, io mem 0x12580000
[   49.664542] exynos-ehci 12580000.ehci: USB 2.0 started, EHCI 1.00
[   49.669652] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.03
[   49.677442] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   49.684628] usb usb1: Product: EHCI Host Controller
[   49.689455] usb usb1: Manufacturer: Linux 5.3.0-rc8+ ehci_hcd
[   49.695295] usb usb1: SerialNumber: 12580000.ehci
[   49.700947] hub 1-0:1.0: USB hub found
[   49.703867] hub 1-0:1.0: 3 ports detected
[   49.758596] gpiohack xmm6262: link active? 1
[   50.074668] usb 1-2: new high-speed USB device number 2 using exynos-ehci
[   50.291938] usb 1-2: New USB device found, idVendor=1519, idProduct=0020, bcdDevice=12.74
[   50.298812] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   50.305913] usb 1-2: Product: HSIC Device
[   50.309758] usb 1-2: Manufacturer: Comneon
[   50.313847] usb 1-2: SerialNumber: 0123456789

libsamsung-ipc: 5a1f981743c0df1d1686632e8897d455b9da18a9
Linux: f72efb034be201930826bf5b04239f9cf3c529f8

Actions #5

Updated by Denis 'GNUtoo' Carikli about 5 years ago

We now can receive samsung-ipc messages:

[ipc] generic_boot complete
Bus 001 Device 002: ID 1519:0020 Comneon HSIC Device
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
main: ipc_client_boot(client) => 0
main: ipc_client_power_on(client) => 0
[ipc] ipc_client_open: client: 0x487598 client->handlers: 0x4875b8 client->handlers->open: 0xb6ed0090
[ipc] ipc_client_open: ->open(client->handlers->transport_data:0x4875f8, client->type:(nil)
generic_open: data: 0x4875f8, type: (nil)
ENTER xmm626_sec_modem_open
xmm626_sec_modem_open: type: 0
generic_open: return 0;
main: ipc_client_open(client) => 0
poll returns 1
[ipc] 

[ipc] xmm626_sec_modem_fmt_recv: Received FMT message
[ipc] xmm626_sec_modem_fmt_recv: Message: aseq=0xff, command=IPC_PWR_PHONE_PWR_UP, type=IPC_TYPE_NOTI, size=0
poll returns 1
[ipc] 

[ipc] xmm626_sec_modem_fmt_recv: Received FMT message
[ipc] xmm626_sec_modem_fmt_recv: Message: aseq=0x00, command=IPC_MISC_ME_IMSI, type=IPC_TYPE_NOTI, size=16

Actions #6

Updated by dl lud over 4 years ago

  • Target version changed from Replicant 9.0 to replicant 10.0
Actions #7

Updated by Denis 'GNUtoo' Carikli about 4 years ago

  • Target version changed from replicant 10.0 to Replicant 11.0 0001
Actions #8

Updated by Denis 'GNUtoo' Carikli about 4 years ago

  • Grant set to Porting Replicant to Android 9 (NLnet Foundation)
Actions #9

Updated by Denis 'GNUtoo' Carikli about 4 years ago

Now that the modem has been validated to work (with ugly code, blocking bugs, etc which is not usable as-is), most of actual focus of the work is to clean that up and integrating it in the various components.

Actions #10

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

Right now under Replicant 11 I have:

console:/ # logcat -b radio                                                    
--------- beginning of radio
01-10 17:57:37.583   283   283 D RILD    : **RIL Daemon Started**
01-10 17:57:37.583   283   283 D RILD    : **RILd param count=6**
01-10 17:57:37.626   287   287 D RILD    : **RIL Daemon Started**
01-10 17:57:37.627   287   287 D RILD    : **RILd param count=1**
01-10 17:57:37.653   283   283 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:37.653   283   283 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:37.700   287   287 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:37.701   287   287 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:37.956   287   287 D RILD    : RIL_Init rilInit completed
01-10 17:57:37.956   287   287 I RILC    : SIM_COUNT: 1
01-10 17:57:37.957   287   287 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:57:37.957   287   287 D RILD    : RIL_Init RIL_register completed
01-10 17:57:37.957   287   287 D RILD    : RIL_register_socket completed
01-10 17:57:41.721   206   206 D TelephonyManager: /proc/cmdline= console=ram loglevel=8 sec_debug.level=0 sec_watchdog.sec_pet=5 androidboot.debug_level=0xXXXX sec_log=0x100000@0x46000000 s3cfb.bootloaderfb=XXXXXXXXXX lcdtype=XX consoleblank=0 lpcharge=0 lpj=XXXXXXX vmalloc=144m oops=panic pmic_info=65 cordon=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX connie=GT-I9300_XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX androidboot.emmc_checksum=3 androidboot.odin_download=1 androidboot.bootloader=XXXXXXXXXXXX androidboot.serialno=XXXXXXXXXXXXXXXX snd_soc_core.pmdown_time=1000 root=PARTLABEL=SYSTEM init=/init rootwait console=ttySAC2,115200 loglevel=8 androidboot.hardware=smdk4x12 androidboot.selinux=permissive enforcing=0 exynosdrm.pixel_order=1
01-10 17:57:42.357   351   351 D RILD    : **RIL Daemon Started**
01-10 17:57:42.357   351   351 D RILD    : **RILd param count=1**
01-10 17:57:42.365   351   351 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:42.365   351   351 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:42.623   351   351 D RILD    : RIL_Init rilInit completed
01-10 17:57:42.623   351   351 I RILC    : SIM_COUNT: 1
01-10 17:57:42.623   351   351 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:57:42.623   351   351 D RILD    : RIL_Init RIL_register completed
01-10 17:57:42.623   351   351 D RILD    : RIL_register_socket completed
01-10 17:57:47.356   408   408 D RILD    : **RIL Daemon Started**
01-10 17:57:47.356   408   408 D RILD    : **RILd param count=1**
01-10 17:57:47.365   408   408 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:47.365   408   408 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:47.622   408   408 D RILD    : RIL_Init rilInit completed
01-10 17:57:47.623   408   408 I RILC    : SIM_COUNT: 1
01-10 17:57:47.623   408   408 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:57:47.623   408   408 D RILD    : RIL_Init RIL_register completed
01-10 17:57:47.623   408   408 D RILD    : RIL_register_socket completed
01-10 17:57:52.368   508   508 D RILD    : **RIL Daemon Started**
01-10 17:57:52.368   508   508 D RILD    : **RILd param count=1**
01-10 17:57:52.378   508   508 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:52.378   508   508 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:52.634   508   508 D RILD    : RIL_Init rilInit completed
01-10 17:57:52.634   508   508 I RILC    : SIM_COUNT: 1
01-10 17:57:52.634   508   508 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:57:52.634   508   508 D RILD    : RIL_Init RIL_register completed
01-10 17:57:52.634   508   508 D RILD    : RIL_register_socket completed
01-10 17:57:52.714   364   364 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:52.864   364   449 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:52.931   364   364 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:53.060   364   364 D TelephonyRegistry: systemRunning register for intents
01-10 17:57:53.610   364   389 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:53.893   364   379 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:54.635   654   654 D TelephonyComponentFactory: validated paths: null
01-10 17:57:54.635   654   654 D TelephonyComponentFactory: Total components injected: 0
01-10 17:57:54.637   654   654 D TDC     : updateOrInsert: inserting: Modem { uuid=modem, state=0, rilModel=0, rat={}, maxActiveVoiceCall=1, maxActiveDataCall=1, maxStandby=1 }
01-10 17:57:54.638   654   654 D TDC     : updateOrInsert: inserting: Sim { uuid=sim, modemUuid=modem, state=0 }
01-10 17:57:54.672   654   654 E PersistAtomsStorage: cannot load/parse PersistAtoms
01-10 17:57:54.672   654   654 E PersistAtomsStorage: java.nio.file.NoSuchFileException: /data/user_de/0/com.android.phone/files/persist_atoms.pb
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:214)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at java.nio.file.Files.newByteChannel(Files.java:361)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at java.nio.file.Files.newByteChannel(Files.java:407)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at java.nio.file.Files.readAllBytes(Files.java:3152)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.telephony.metrics.PersistAtomsStorage.loadAtomsFromFile(PersistAtomsStorage.java:132)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.telephony.metrics.PersistAtomsStorage.<init>(PersistAtomsStorage.java:60)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.telephony.metrics.MetricsCollector.<init>(MetricsCollector.java:88)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.telephony.PhoneFactory.makeDefaultPhone(PhoneFactory.java:149)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.telephony.PhoneFactory.makeDefaultPhones(PhoneFactory.java:105)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.phone.PhoneGlobals.onCreate(PhoneGlobals.java:339)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.phone.PhoneApp.onCreate(PhoneApp.java:39)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1192)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.app.ActivityThread.handleBindApplication(ActivityThread.java:6712)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.app.ActivityThread.access$1300(ActivityThread.java:237)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1913)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.os.Handler.dispatchMessage(Handler.java:106)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.os.Looper.loop(Looper.java:223)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at android.app.ActivityThread.main(ActivityThread.java:7656)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at java.lang.reflect.Method.invoke(Native Method)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:592)
01-10 17:57:54.672   654   654 E PersistAtomsStorage:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:947)
01-10 17:57:54.676   654   654 D PersistAtomsStorage: created new PersistAtoms
01-10 17:57:54.682   654   654 D MetricsCollector: registered
01-10 17:57:54.687   654   654 D CdmaSSM : subscriptionSource from settings: 0
01-10 17:57:54.689   654   654 I PhoneFactory: Cdma Subscription set to 0
01-10 17:57:54.690   654   654 I PhoneFactory: Network Mode set to 0
01-10 17:57:54.691   654   654 D RILJ    : RIL: init preferredNetworkType=0 cdmaSubscription=0) [PHONEnull]
01-10 17:57:54.741   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:54.741   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:54.741   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:54.742   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:54.744   654   654 E RILJ    : IOemHook service is not on the device HAL: java.util.NoSuchElementException [PHONE0]
01-10 17:57:54.744   654   654 D RILJ    : Radio HAL version: -1.-1 [PHONE0]
01-10 17:57:54.744   654   654 D UiccController: Creating UiccController
01-10 17:57:54.745   654   654 D UiccController: config_num_physical_slots = 1
01-10 17:57:54.766   654   654 I PhoneFactory: Creating SubscriptionController
01-10 17:57:54.854   364   364 D TelephonyRegistry: notifyCellLocationForSubscriber: subId=0 cellLocation=null
01-10 17:57:54.885   654   673 D SubscriptionController: [getActiveSubscriptionInfo]- subId=0 subList=[] subInfo=null
01-10 17:57:54.888   654   654 D SubscriptionController: [SubscriptionController] init by Context
01-10 17:57:54.911   654   654 I PhoneFactory: Creating Phone with type = 1 phoneId = 0
01-10 17:57:54.913   654   654 D TelephonyTester: register for intent action=com.android.internal.telephony.action_detached
01-10 17:57:54.913   654   654 D TelephonyTester: register for intent action=com.android.internal.telephony.action_attached
01-10 17:57:54.913   654   654 D TelephonyTester: register for intent action=com.android.internal.telephony.TestServiceState
01-10 17:57:54.913   654   654 D TelephonyTester: register for intent action=com.android.internal.telephony.TestChangeNumber
01-10 17:57:54.937   654   654 D Phone   : mDoesRilSendMultipleCallRing=true
01-10 17:57:54.937   654   654 D Phone   : mCallRingDelay=3000
01-10 17:57:54.996   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:54.996   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:55.002   654   654 D SmsDispatchersController: SmsDispatchersController created
01-10 17:57:55.037   654   654 E ImsSmsDispatcher [0]: Failed to get sms format. Error: getSmsFormat()
01-10 17:57:55.037   654   654 D SMSDispatcher: SMSDispatcher: ctor mSmsCapable=true format=unknown mSmsSendDisabled=false
01-10 17:57:55.038   654   654 W FeatureConnector: [ImsSmsDispatcher, 0] connect: not supported.
01-10 17:57:55.051   654   654 D SMSDispatcher: SMSDispatcher: ctor mSmsCapable=true format=3gpp2 mSmsSendDisabled=false
01-10 17:57:55.051   654   654 D CdmaSMSDispatcher: CdmaSMSDispatcher created
01-10 17:57:55.060   654   654 D GsmInboundSmsHandler: created InboundSmsHandler
01-10 17:57:55.076   654   818 D GsmInboundSmsHandler: StartupState.enter: entering StartupState
01-10 17:57:55.087   654   654 D CdmaInboundSmsHandler: created InboundSmsHandler
01-10 17:57:55.096   654   819 D CdmaInboundSmsHandler: StartupState.enter: entering StartupState
01-10 17:57:55.100   654   654 D SMSDispatcher: SMSDispatcher: ctor mSmsCapable=true format=3gpp mSmsSendDisabled=false
01-10 17:57:55.101   654   654 D GsmSMSDispatcher: GsmSMSDispatcher created
01-10 17:57:55.102   654   818 D GsmInboundSmsHandler: StartupState.processMessage: processing EVENT_START_ACCEPTING_SMS
01-10 17:57:55.104   654   819 D CdmaInboundSmsHandler: StartupState.processMessage: processing EVENT_START_ACCEPTING_SMS
01-10 17:57:55.104   654   819 D CdmaInboundSmsHandler: IdleState.enter: entering IdleState
01-10 17:57:55.104   654   818 D GsmInboundSmsHandler: IdleState.enter: entering IdleState
01-10 17:57:55.104   654   819 D CdmaInboundSmsHandler: IdleState.processMessage: processing EVENT_RELEASE_WAKELOCK
01-10 17:57:55.105   654   818 D GsmInboundSmsHandler: IdleState.processMessage: processing EVENT_RELEASE_WAKELOCK
01-10 17:57:55.107   654   818 D GsmInboundSmsHandler: IdleState.processMessage: EVENT_RELEASE_WAKELOCK: mWakeLock released
01-10 17:57:55.108   654   819 D CdmaInboundSmsHandler: IdleState.processMessage: EVENT_RELEASE_WAKELOCK: mWakeLock released
01-10 17:57:55.109   654   654 D CdmaSSM : subscriptionSource from settings: 0
01-10 17:57:55.109   654   654 D CdmaSSM : cdmaSSM constructor: 0
01-10 17:57:55.114   654   654 D GsmCdmaPhone: [0] Precise phone type 1
01-10 17:57:55.114   654   654 D RILJ    : setPhoneType=1 old value=0 [PHONE0]
01-10 17:57:55.120   654   654 D CarrierActionAgent: [0]Creating CarrierActionAgent
01-10 17:57:55.121   654   654 W CarrierConfigManager: Error getting config for subId -1 ICarrierConfigLoader is null
01-10 17:57:55.123   654   654 D TransportManager: operates in legacy mode.
01-10 17:57:55.131   654   654 W CarrierConfigManager: Error getting config for subId -1 ICarrierConfigLoader is null
01-10 17:57:55.133   364   378 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.137   654   654 D NRM-C-0 : registerForNetworkRegistrationInfoChanged
01-10 17:57:55.186   654   654 D NewNitzStateMachineImpl: handleNetworkUnavailable(): mLatestNitzSignal was already null. Nothing to do.
01-10 17:57:55.192   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:55.192   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:55.192   654   654 D SST     : [0] notifyVoiceRegStateRilRadioTechnologyChanged: vrs=1 rat=0
01-10 17:57:55.198   364   675 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.340   654   654 E EmergencyNumberTracker: Initialize ota emergency database file input failure: java.io.FileNotFoundException: /data/misc/emergencynumberdb/emergency_number_db: open failed: ENOENT (No such file or directory)
01-10 17:57:55.341   654   654 W CarrierConfigManager: Error getting config for subId -1 ICarrierConfigLoader is null
01-10 17:57:55.504   654   654 D EmergencyNumberTracker:  asset emergency database is loaded. Ver: 1 Phone Id: 0
01-10 17:57:55.506   654   654 E EmergencyNumberTracker: Cache ota emergency database IOException: java.io.FileNotFoundException: /data/misc/emergencynumberdb/emergency_number_db: open failed: ENOENT (No such file or directory)
01-10 17:57:55.506   654   654 D EmergencyNumberTracker: Using Asset Emergency database. Version: 1
01-10 17:57:55.507   364   378 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.525   498   498 W CarrierConfigManager: Error getting config for subId -1 ICarrierConfigLoader is null
01-10 17:57:55.528   654   654 D SubscriptionController: Valid row not present in db
01-10 17:57:55.530   654   654 D SubscriptionController: getSubscriptionProperty Query value = null
01-10 17:57:55.539   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:55.582   364   378 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.603   654   654 D m.android.phon: DCT.constructor
01-10 17:57:55.620   654   654 D Dcc-C-0 : E ctor
01-10 17:57:55.621   654   654 D Dcc-C-0 : X ctor
01-10 17:57:55.621   654   654 D DcTesterDeacativateAll: register for intent action=com.android.internal.telephony.dataconnection.action_deactivate_all
01-10 17:57:55.621   654   654 D DcTesterDeacativateAll: register for intent action=com.android.internal.telephony.action_detached
01-10 17:57:55.626   654   654 D DcTesterFailBrinupAll: register for intent action=com.android.internal.telephony.dataconnection.action_fail_bringup
01-10 17:57:55.626   654   654 D DcTesterFailBrinupAll: register for intent action=com.android.internal.telephony.action_detached
01-10 17:57:55.626   654   654 D DcTesterFailBrinupAll: register for intent action=com.android.internal.telephony.action_attached
01-10 17:57:55.630   654   654 W CarrierConfigManager: Error getting config for subId -1 ICarrierConfigLoader is null
01-10 17:57:55.631   654   654 D DCT-C-0 : initApnContexts: E
01-10 17:57:55.631   654   654 W ApnConfigTypeRepository: carrier config is null
01-10 17:57:55.632   654   654 D DCT-C-0 : initApnContexts: apnContext=hipri
01-10 17:57:55.632   654   654 D DCT-C-0 : initApnContexts: apnContext=fota
01-10 17:57:55.633   654   654 D DCT-C-0 : initApnContexts: apnContext=ims
01-10 17:57:55.633   654   654 D DCT-C-0 : initApnContexts: apnContext=cbs
01-10 17:57:55.634   654   654 D DCT-C-0 : initApnContexts: apnContext=ia
01-10 17:57:55.634   654   654 D DCT-C-0 : initApnContexts: apnContext=emergency
01-10 17:57:55.634   654   654 D DCT-C-0 : initApnContexts: apnContext=mcx
01-10 17:57:55.634   654   654 D DCT-C-0 : initApnContexts: apnContext=xcap
01-10 17:57:55.635   654   654 D DCT-C-0 : initApnContexts: apnContext=default
01-10 17:57:55.635   654   654 D DCT-C-0 : initApnContexts: apnContext=mms
01-10 17:57:55.635   654   654 D DCT-C-0 : initApnContexts: apnContext=supl
01-10 17:57:55.636   654   654 D DCT-C-0 : initApnContexts: apnContext=dun
01-10 17:57:55.669   654   654 D DCT-C-0 : Adding emergency APN : [ApnSettingV7] Emergency, 0, null, sos, null, null, null, null, null, 0, emergency, IPV4V6, IPV4V6, false, 0, false, 0, 0, 0, 0, null, null, false, 135168, 0, -1, -1
01-10 17:57:55.672   654   654 D CarrierResolver: Creating CarrierResolver[0]
01-10 17:57:55.675   654   654 D SST     : [0] notifyVoiceRegStateRilRadioTechnologyChanged: vrs=1 rat=0
01-10 17:57:55.680   654   654 I GsmCdmaPhone: [0] updateTtyMode ttyMode=0
01-10 17:57:55.680   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:55.680   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:55.683   654   654 I GsmCdmaPhone: [0] updateUiTtyMode ttyMode=0
01-10 17:57:55.683   654   654 D GsmCdmaPhone: [0] GsmCdmaPhone: constructor: sub = 0
01-10 17:57:55.743   654   654 I PhoneFactory: defaultSmsApplication: com.android.messaging
01-10 17:57:55.746   654   654 I PhoneFactory: Creating SubInfoRecordUpdater 
01-10 17:57:55.751   654   654 D SubscriptionInfoUpdater: Constructor invoked
01-10 17:57:55.766   654   654 I PhoneFactory: IMS is not supported on this device, skipping ImsResolver.
01-10 17:57:55.769   364   676 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.772   654   654 D PhoneSwitcher: PhoneSwitcher started
01-10 17:57:55.775   654   654 D ProxyController: Constructor - Enter
01-10 17:57:55.783   654   654 D ProxyController: clearTransaction
01-10 17:57:55.783   654   654 D ProxyController: clearTransaction: phoneId=0 status=IDLE
01-10 17:57:55.784   654   654 D ProxyController: Constructor - Exit
01-10 17:57:55.802   364   676 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.802   654   654 D TelephonyNetworkFactory[0]: Registering NetworkFactory
01-10 17:57:55.809   654   654 D CallManager: registerPhone(GSM Handler (com.android.internal.telephony.GsmCdmaPhone) {5dd2b4d})
01-10 17:57:55.843   364   675 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.844   654   654 D CallManager: registerForMmiComplete
01-10 17:57:55.846   654   654 D NewNitzStateMachineImpl: handleAirplaneModeChanged(true): mLatestNitzSignal was already null. Nothing to do.
01-10 17:57:55.855   364   675 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:57:55.863   654   654 D UiccController: handleMessage: Received RADIO_UNAVAILABLE for phoneId 0
01-10 17:57:55.863   654   654 D UiccController: EVENT_RADIO_UNAVAILABLE, dispose card
01-10 17:57:56.080   654   654 D Phone   : config LCE service failed: com.android.internal.telephony.CommandException: RADIO_NOT_AVAILABLE
01-10 17:57:56.080   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:57:56.081   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:57:56.081   654   654 D GsmSMSDispatcher: GsmSMSDispatcher: subId = -1 slotId = 0
01-10 17:57:56.081   654   654 D GsmCdmaPhone: [0] Event EVENT_RADIO_OFF_OR_NOT_AVAILABLE Received
01-10 17:57:56.082   654   654 D GsmCdmaPhone: [0] EVENT EVENT_RADIO_STATE_CHANGED
01-10 17:57:56.082   654   654 D GsmCdmaPhone: handleRadioPowerStateChange, state= 2
01-10 17:57:56.083   654   654 D SST     : [0] EVENT_ICC_CHANGED: SIM absent
01-10 17:57:56.083   654   654 D SST     : [0] cancelAllNotifications: mPrevSubId=-1
01-10 17:57:56.089   654   654 D NRM-C-0 : Trying to bind com.android.phone for transport WWAN
01-10 17:57:56.093   654   654 D SST     : [0] mDeviceShuttingDown=false, mDesiredPowerState=false, getRadioState=2, mPowerOffDelayNeed=true, mAlarmSwitch=false, mRadioDisabledByCarrier=false
01-10 17:57:56.094   654   654 D SST     : [0] pollState: modemTriggered=true
01-10 17:57:56.094   654   654 D NewNitzStateMachineImpl: handleNetworkUnavailable(): mLatestNitzSignal was already null. Nothing to do.
01-10 17:57:56.095   654   654 D SST     : [0] Poll ServiceState done:  oldSS=[{mVoiceRegState=1(OUT_OF_SERVICE), mDataRegState=1(OUT_OF_SERVICE), mChannelNumber=-1, duplexMode()=0, mCellBandwidths=[], mOperatorAlphaLong=null, mOperatorAlphaShort=null, isManualNetworkSelection=false(automatic), getRilVoiceRadioTechnology=0(Unknown), getRilDataRadioTechnology=0(Unknown), mCssIndicator=unsupported, mNetworkId=-1, mSystemId=-1, mCdmaRoamingIndicator=-1, mCdmaDefaultRoamingIndicator=-1, mIsEmergencyOnly=false, isUsingCarrierAggregation=false, mLteEarfcnRsrpBoost=0, mNetworkRegistrationInfos=[NetworkRegistrationInfo{ domain=CS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}, NetworkRegistrationInfo{ domain=PS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}], mNrFrequencyRange=0, mOperatorAlphaLongRaw=null, mOperatorAlphaShortRaw=null, mIsDataRoamingFromRegistration=false, mIsIwlanPreferred=false}] newSS=[{mVoiceRegState=1(OUT_OF_SERVICE), mDataRegState=1(OUT_OF_SERVICE), mChannelNumber=-1, duplexMode()=0, mCellBandwidths=[], mOperatorAlphaLong=null, mOperatorAlphaShort=null, isManualNetworkSelection=false(automatic), getRilVoiceRadioTechnology=0(Unknown), getRilDataRadioTechnology=0(Unknown), mCssIndicator=unsupported, mNetworkId=-1, mSystemId=-1, mCdmaRoamingIndicator=-1, mCdmaDefaultRoamingIndicator=-1, mIsEmergencyOnly=false, isUsingCarrierAggregation=false, mLteEarfcnRsrpBoost=0, mNetworkRegistrationInfos=[NetworkRegistrationInfo{ domain=CS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}, NetworkRegistrationInfo{ domain=PS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}], mNrFrequencyRange=0, mOperatorAlphaLongRaw=null, mOperatorAlphaShortRaw=null, mIsDataRoamingFromRegistration=false, mIsIwlanPreferred=false}] oldMaxDataCalls=1 mNewMaxDataCalls=1 oldReasonDataDenied=-1 mNewReasonDataDenied=-1
01-10 17:57:56.099   654   654 D SST     : [0] pollStateDone: hasRegistered = false hasDeregistered = false hasDataAttached = {1=false} hasDataDetached = {1=false} hasDataRegStateChanged = {1=false} hasRilVoiceRadioTechnologyChanged = false hasRilDataRadioTechnologyChanged = {1=false} hasDataTransportPreferenceChanged = false hasChanged = false hasVoiceRoamingOn = false hasVoiceRoamingOff = false hasDataRoamingOn =false hasDataRoamingOff = false hasLocationChanged = false has4gHandoff = false hasMultiApnSupport = false hasLostMultiApnSupport = false hasCssIndicatorChanged = false hasNrFrequencyRangeChanged = false hasNrStateChanged = false hasAirplaneModeOnlChanged = false
01-10 17:57:56.099   654   654 D SST     : [0] mDeviceShuttingDown=false, mDesiredPowerState=false, getRadioState=2, mPowerOffDelayNeed=true, mAlarmSwitch=false, mRadioDisabledByCarrier=false
01-10 17:57:56.100   654   654 D SST     : [0] pollState: modemTriggered=true
01-10 17:57:56.100   654   654 D NewNitzStateMachineImpl: handleNetworkUnavailable(): mLatestNitzSignal was already null. Nothing to do.
01-10 17:57:56.102   654   654 D SST     : [0] Poll ServiceState done:  oldSS=[{mVoiceRegState=1(OUT_OF_SERVICE), mDataRegState=1(OUT_OF_SERVICE), mChannelNumber=-1, duplexMode()=0, mCellBandwidths=[], mOperatorAlphaLong=null, mOperatorAlphaShort=null, isManualNetworkSelection=false(automatic), getRilVoiceRadioTechnology=0(Unknown), getRilDataRadioTechnology=0(Unknown), mCssIndicator=unsupported, mNetworkId=-1, mSystemId=-1, mCdmaRoamingIndicator=-1, mCdmaDefaultRoamingIndicator=-1, mIsEmergencyOnly=false, isUsingCarrierAggregation=false, mLteEarfcnRsrpBoost=0, mNetworkRegistrationInfos=[NetworkRegistrationInfo{ domain=CS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}, NetworkRegistrationInfo{ domain=PS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}], mNrFrequencyRange=0, mOperatorAlphaLongRaw=null, mOperatorAlphaShortRaw=null, mIsDataRoamingFromRegistration=false, mIsIwlanPreferred=false}] newSS=[{mVoiceRegState=1(OUT_OF_SERVICE), mDataRegState=1(OUT_OF_SERVICE), mChannelNumber=-1, duplexMode()=0, mCellBandwidths=[], mOperatorAlphaLong=null, mOperatorAlphaShort=null, isManualNetworkSelection=false(automatic), getRilVoiceRadioTechnology=0(Unknown), getRilDataRadioTechnology=0(Unknown), mCssIndicator=unsupported, mNetworkId=-1, mSystemId=-1, mCdmaRoamingIndicator=-1, mCdmaDefaultRoamingIndicator=-1, mIsEmergencyOnly=false, isUsingCarrierAggregation=false, mLteEarfcnRsrpBoost=0, mNetworkRegistrationInfos=[NetworkRegistrationInfo{ domain=CS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}, NetworkRegistrationInfo{ domain=PS transportType=WWAN registrationState=UNKNOWN roamingType=NOT_ROAMING accessNetworkTechnology=UNKNOWN rejectCause=0 emergencyEnabled=false availableServices=[] cellIdentity=null voiceSpecificInfo=null dataSpecificInfo=null nrState=NONE rRplmn=}], mNrFrequencyRange=0, mOperatorAlphaLongRaw=null, mOperatorAlphaShortRaw=null, mIsDataRoamingFromRegistration=false, mIsIwlanPreferred=false}] oldMaxDataCalls=1 mNewMaxDataCalls=1 oldReasonDataDenied=-1 mNewReasonDataDenied=-1
01-10 17:57:56.103   654   654 D SST     : [0] pollStateDone: hasRegistered = false hasDeregistered = false hasDataAttached = {1=false} hasDataDetached = {1=false} hasDataRegStateChanged = {1=false} hasRilVoiceRadioTechnologyChanged = false hasRilDataRadioTechnologyChanged = {1=false} hasDataTransportPreferenceChanged = false hasChanged = false hasVoiceRoamingOn = false hasVoiceRoamingOff = false hasDataRoamingOn =false hasDataRoamingOff = false hasLocationChanged = false has4gHandoff = false hasMultiApnSupport = false hasLostMultiApnSupport = false hasCssIndicatorChanged = false hasNrFrequencyRangeChanged = false hasNrStateChanged = false hasAirplaneModeOnlChanged = false
01-10 17:57:56.107   654   654 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:57:56.114   654   654 D SubscriptionController: Valid row not present in db
01-10 17:57:56.116   654   654 D SubscriptionController: getSubscriptionProperty Query value = null
01-10 17:57:56.116   654   654 I CSST    : isNrSupported:  carrierConfigEnabled: true, AccessFamilySupported: false, isNrNetworkTypeAllowed: true
01-10 17:57:56.116   654   654 I CSST    : PrefNetworkNotification: sendMessage() w/values: ,false,-1,false,false
01-10 17:57:56.118   654   654 I CSST    : canceling notifications: 1000
01-10 17:57:56.118   654   654 D Phone   : isWifiCallingEnabled =false
01-10 17:57:56.118   654   654 D CSST    : isPhoneRegisteredForWifiCalling: false
01-10 17:57:56.118   654   654 D Phone   : isWifiCallingEnabled =false
01-10 17:57:56.118   654   654 I CSST    : EmergencyNetworkNotification: sendMessage() w/values: ,-1,false,false
01-10 17:57:56.120   654   654 I CSST    : canceling notifications: 1001
01-10 17:57:56.126   654   654 D SubscriptionController: Valid row not present in db
01-10 17:57:56.128   654   654 D SubscriptionController: getSubscriptionProperty Query value = null
01-10 17:57:56.128   654   654 I CSST    : isNrSupported:  carrierConfigEnabled: true, AccessFamilySupported: false, isNrNetworkTypeAllowed: true
01-10 17:57:56.128   654   654 I CSST    : PrefNetworkNotification: sendMessage() w/values: ,false,-1,false,false
01-10 17:57:56.129   654   654 I CSST    : canceling notifications: 1000
01-10 17:57:56.129   654   654 D Phone   : isWifiCallingEnabled =false
01-10 17:57:56.129   654   654 D CSST    : isPhoneRegisteredForWifiCalling: false
01-10 17:57:56.129   654   654 D Phone   : isWifiCallingEnabled =false
01-10 17:57:56.129   654   654 I CSST    : EmergencyNetworkNotification: sendMessage() w/values: ,-1,false,false
01-10 17:57:56.131   654   654 I CSST    : canceling notifications: 1001
01-10 17:57:56.131   654   654 D EmergencyNumberTracker: updateRadioEmergencyNumberListAndNotify(): receiving []
01-10 17:57:56.131   654   654 D NetworkTypeController: [0] DefaultState: process EVENT_INITIALIZE
01-10 17:57:56.135   654   654 D NetworkTypeController: [0] mOverrideTimerRules: {connected={mState=connected, mOverrideType=NR_NSA, mPrimaryTimers={}, mSecondaryTimers={}}, not_restricted_rrc_con={mState=not_restricted_rrc_con, mOverrideType=NR_NSA, mPrimaryTimers={}, mSecondaryTimers={}}, legacy={mState=legacy, mOverrideType=NONE, mPrimaryTimers={}, mSecondaryTimers={}}, not_restricted_rrc_idle={mState=not_restricted_rrc_idle, mOverrideType=NR_NSA, mPrimaryTimers={}, mSecondaryTimers={}}, restricted={mState=restricted, mOverrideType=NONE, mPrimaryTimers={}, mSecondaryTimers={}}, connected_mmwave={mState=connected_mmwave, mOverrideType=NR_NSA, mPrimaryTimers={}, mSecondaryTimers={}}}
01-10 17:57:56.136   654   654 D NetworkTypeController: [0] DefaultState: process EVENT_UPDATE
01-10 17:57:56.136   654   654 D NetworkTypeController: [0] Entering LegacyState
01-10 17:57:56.136   654   654 D DisplayInfoController: TelephonyDisplayInfo[0] changed from null to TelephonyDisplayInfo {network=UNKNOWN, override=NONE}
01-10 17:57:56.151   654   654 D DCT-C-0 : onDataEnabledChanged: enable=true, enabledChangedReason=0
01-10 17:57:56.152   654   654 D DCT-C-0 : setupDataOnAllConnectableApns: dataEnabled hipri:[state=IDLE,enabled=false] mcx:[state=IDLE,enabled=false] xcap:[state=IDLE,enabled=false] fota:[state=IDLE,enabled=false] ims:[state=IDLE,enabled=false] cbs:[state=IDLE,enabled=false] ia:[state=IDLE,enabled=false] emergency:[state=IDLE,enabled=false] mms:[state=IDLE,enabled=false] supl:[state=IDLE,enabled=false] dun:[state=IDLE,enabled=false] default:[state=IDLE,enabled=false] 
01-10 17:57:56.152   654   654 D DCT-C-0 : onDataEnabledOverrideRulesChanged
01-10 17:57:56.154   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.158   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.161   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.164   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.166   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.170   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.172   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.176   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.178   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.182   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.185   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.189   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.191   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.196   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.198   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.206   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.208   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.212   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.214   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.217   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.220   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.233   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.235   654   654 D DCT-C-0 : shouldRestrictDataForEcbm: isInEcm=false isInImsEcm=false
01-10 17:57:56.238   654   654 D SubscriptionController: [getActiveSubscriptionInfo]- subId=-1 subList=[] subInfo=null
01-10 17:57:56.239   654   654 D DCT-C-0 : onRadioOffOrNotAvailable: is off and clean up all connections
01-10 17:57:56.240   654   654 D DCT-C-0 : cleanUpAllConnectionsInternal: detach=false reason=radioTurnedOff
01-10 17:57:56.244   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=xcap mState=IDLE mWaitingApns={null priority=3} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.246   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=mcx mState=IDLE mWaitingApns={null priority=3} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.248   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=fota mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.250   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=supl mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.253   654   654 D DCT-C-0 : return new LinkProperties
01-10 17:57:56.257   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=emergency mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.259   364   676 D TelephonyRegistry: onDataConnectionStateChanged(DISCONNECTED, UNKNOWN) subId=-1, phoneId=0
01-10 17:57:56.261   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=hipri mState=IDLE mWaitingApns={null priority=3} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.264   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=ims mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.267   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=default mState=IDLE mWaitingApns={null priority=0} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.269   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=mms mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.271   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=cbs mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.273   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=ia mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.281   654   654 D DCT-C-0 : cleanUpConnectionInternal: X detach=false reason=radioTurnedOff apnContext={mApnType=dun mState=IDLE mWaitingApns={null priority=2} mApnSetting={null} mReason=radioTurnedOff mDataEnabled=false} dc=null
01-10 17:57:56.281   654   654 D DCT-C-0 : stopNetStatPoll
01-10 17:57:56.283   654   654 D DCT-C-0 : cleanUpAllConnectionsInternal: mDisconnectPendingCount = 0
01-10 17:57:56.283   654   654 D DCT-C-0 : onDataConnectionDetached: stop polling and notify detached
01-10 17:57:56.283   654   654 D DCT-C-0 : stopNetStatPoll
01-10 17:57:56.284   654   654 D DCT-C-0 : get all active apn types
01-10 17:57:56.284   654   654 D DCT-C-0 : onDataRoamingOff
01-10 17:57:56.287   654   654 D DCT-C-0 : get all active apn types
01-10 17:57:56.287   654   654 D CarrierResolver: handleMessage: 2
01-10 17:57:56.288   654   654 D GsmCdmaPhone: [0] onVoiceRegStateOrRatChanged
01-10 17:57:56.288   654   654 D GsmCdmaPhone: [0] getCsCallRadioTech, current vrs=1, vrat=0
01-10 17:57:56.288   654   654 D GsmCdmaPhone: [0] getCsCallRadioTech, result calcVrat=0
01-10 17:57:56.288   654   654 D DCT-C-0 : onDataEnabledChanged: enable=true, enabledChangedReason=0
01-10 17:57:56.288   654   654 D DCT-C-0 : setupDataOnAllConnectableApns: dataEnabled hipri:[state=IDLE,enabled=false] mcx:[state=IDLE,enabled=false] xcap:[state=IDLE,enabled=false] fota:[state=IDLE,enabled=false] ims:[state=IDLE,enabled=false] cbs:[state=IDLE,enabled=false] ia:[state=IDLE,enabled=false] emergency:[state=IDLE,enabled=false] mms:[state=IDLE,enabled=false] supl:[state=IDLE,enabled=false] dun:[state=IDLE,enabled=false] default:[state=IDLE,enabled=false] 
01-10 17:57:56.289   654   654 D PhoneSwitcher: No active subscriptions: resetting preferred phone to 0 for emergency
01-10 17:57:56.290   654   654 D PhoneSwitcher: evaluating due to EVENT_PRECISE_CALL_STATE_CHANGED phone[0] 0->-1
01-10 17:57:56.291   654   654 D PhoneSwitcher: activate 0
01-10 17:57:56.291   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.295   654   654 D PhoneSwitcher: logDataSwitchEvent subId -1 state 1 reason 2
01-10 17:57:56.308   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ TRACK_DEFAULT id=9, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1073 AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ] with score 0 and providerId -1
01-10 17:57:56.309   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ REQUEST id=11, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ] with score 0 and providerId -1
01-10 17:57:56.309   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ TRACK_DEFAULT id=13, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ] with score 0 and providerId -1
01-10 17:57:56.309   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ REQUEST id=1, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 0 and providerId -1
01-10 17:57:56.309   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ TRACK_DEFAULT id=14, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ] with score 0 and providerId -1
01-10 17:57:56.310   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ TRACK_DEFAULT id=8, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 0 and providerId -1
01-10 17:57:56.310   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ BACKGROUND_REQUEST id=2, [ Transports: CELLULAR Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] with score 0 and providerId -1
01-10 17:57:56.312   654   654 D DebugService: DebugService DebugService:
01-10 17:57:56.317   654   654 D GsmSMSDispatcher: GsmSMSDispatcher: subId = -1 slotId = 0
01-10 17:57:56.318   654   654 D SST     : [0] EVENT_ICC_CHANGED: SIM absent
01-10 17:57:56.318   654   654 D SST     : [0] cancelAllNotifications: mPrevSubId=-1
01-10 17:57:56.318   654   654 D CarrierResolver: handleMessage: 2
01-10 17:57:56.318   654   654 D GsmCdmaCallTracker: Event EVENT_POLL_CALLS_RESULT Received
01-10 17:57:56.319   654   654 D GsmCdmaCallTracker: [0] update phone state, old=IDLE new=IDLE
01-10 17:57:56.323   654   654 D NetworkService: network service created
01-10 17:57:56.324   654   654 D NetworkTypeController: [0] LegacyState: process EVENT_DATA_RAT_CHANGED
01-10 17:57:56.325   654   654 D DCT-C-0 : reevaluateUnmeteredConnections
01-10 17:57:56.329   654   654 D DataService: Data service created
01-10 17:57:56.331   654   654 D TelephonyNetworkFactory[0]: got request NetworkRequest [ TRACK_DEFAULT id=17, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1001 AdministratorUids: [] RequestorUid: 1001 RequestorPackageName: com.android.phone] ] with score 0 and providerId 0
01-10 17:57:56.334   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=9, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1073 AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ]
01-10 17:57:56.335   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.336   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.339   654   654 D PhoneSwitcher: Added DcRequest, size: 1
01-10 17:57:56.351   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ REQUEST id=11, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ]
01-10 17:57:56.351   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.351   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.353   654   654 D PhoneSwitcher: Added DcRequest, size: 2
01-10 17:57:56.361   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=13, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ]
01-10 17:57:56.361   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.362   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.364   654   654 D PhoneSwitcher: Added DcRequest, size: 3
01-10 17:57:56.368   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ REQUEST id=1, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ]
01-10 17:57:56.368   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.369   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.371   654   654 D PhoneSwitcher: Added DcRequest, size: 4
01-10 17:57:56.380   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=14, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ]
01-10 17:57:56.381   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.381   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.383   654   654 D PhoneSwitcher: Added DcRequest, size: 5
01-10 17:57:56.385   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=8, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ]
01-10 17:57:56.385   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.385   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.387   654   654 D PhoneSwitcher: Added DcRequest, size: 6
01-10 17:57:56.389   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ BACKGROUND_REQUEST id=2, [ Transports: CELLULAR Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ]
01-10 17:57:56.390   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.390   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.392   654   654 D PhoneSwitcher: Added DcRequest, size: 7
01-10 17:57:56.393   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ TRACK_DEFAULT id=9, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1073 AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ] shouldApply false
01-10 17:57:56.394   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ REQUEST id=11, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1073 RequestorPackageName: com.android.networkstack] ] shouldApply false
01-10 17:57:56.395   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ TRACK_DEFAULT id=13, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ] shouldApply false
01-10 17:57:56.395   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ REQUEST id=1, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] shouldApply false
01-10 17:57:56.396   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ TRACK_DEFAULT id=14, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 10092 AdministratorUids: [] RequestorUid: 10092 RequestorPackageName: com.android.systemui] ] shouldApply false
01-10 17:57:56.397   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ TRACK_DEFAULT id=8, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1000 AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] shouldApply false
01-10 17:57:56.397   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ BACKGROUND_REQUEST id=2, [ Transports: CELLULAR Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN AdministratorUids: [] RequestorUid: 1000 RequestorPackageName: android] ] shouldApply false
01-10 17:57:56.398   654   654 D NRM-C-0 : service ComponentInfo{com.android.phone/com.android.internal.telephony.CellularNetworkService} for transport WWAN is now connected.
01-10 17:57:56.401   654   654 D DSM-C-0 : onServiceConnected
01-10 17:57:56.403   654   845 D CellularDataService: Cellular data service created for slot 0
01-10 17:57:56.432   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=17, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1001 AdministratorUids: [] RequestorUid: 1001 RequestorPackageName: com.android.phone] ]
01-10 17:57:56.433   654   654 D PhoneSwitcher: evaluating due to netRequest
01-10 17:57:56.434   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:57:56.436   654   654 D PhoneSwitcher: Added DcRequest, size: 8
01-10 17:57:56.440   654   654 D TelephonyNetworkFactory[0]: onNeedNetworkFor NetworkRequest [ TRACK_DEFAULT id=17, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1001 AdministratorUids: [] RequestorUid: 1001 RequestorPackageName: com.android.phone] ] shouldApply false
01-10 17:57:57.243   654   823 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:57:57.366   851   851 D RILD    : **RIL Daemon Started**
01-10 17:57:57.366   851   851 D RILD    : **RILd param count=1**
01-10 17:57:57.374   851   851 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:57:57.374   851   851 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:57:57.629   851   851 D RILD    : RIL_Init rilInit completed
01-10 17:57:57.629   851   851 I RILC    : SIM_COUNT: 1
01-10 17:57:57.629   851   851 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:57:57.629   851   851 D RILD    : RIL_Init RIL_register completed
01-10 17:57:57.629   851   851 D RILD    : RIL_register_socket completed
01-10 17:57:59.188   654   654 D ONSNetworkScanCtlr: init called
01-10 17:57:59.211   364   422 D TelephonyRegistry: listen ooscl: hasNotifyOpptSubInfoChangedOccurred==false no callback
01-10 17:57:59.212   654   654 D ONSProfileSelector: ONSProfileSelector init complete
01-10 17:57:59.228   654   654 D ONS     : service is enable state true
01-10 17:57:59.796   654   654 D WAP PUSH: Received broadcast android.intent.action.USER_UNLOCKED
01-10 17:57:59.805   654   654 D WAP PUSH: Received broadcast android.intent.action.USER_UNLOCKED
01-10 17:57:59.805   654   654 D SmsBroadcastUndelivered: Received broadcast android.intent.action.USER_UNLOCKED
01-10 17:57:59.806   654   654 D SmsDispatchersController: Received broadcast android.intent.action.USER_UNLOCKED
01-10 17:57:59.829   654   915 D SmsBroadcastUndelivered: scanning raw table for undelivered messages
01-10 17:58:00.089   654   915 D SmsBroadcastUndelivered: finished scanning raw table in 259 ms
01-10 17:58:00.276   654   672 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:00.284   654   672 I chatty  : uid=1001(radio) Binder:654_1 identical 1 line
01-10 17:58:00.293   654   672 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:00.944   654   835 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:00.947   654   835 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:01.307   654   654 D DcRequest: Cellular request confirmed: NetworkRequest [ TRACK_DEFAULT id=17, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1001 AdministratorUids: [] RequestorUid: 1001 RequestorPackageName: com.android.phone] ]
01-10 17:58:01.308   654   654 D PhoneSwitcher: evaluating due to netReleased
01-10 17:58:01.308   654   654 D PhoneSwitcher: notifyPreferredDataSubIdChanged to -1
01-10 17:58:01.315   654   654 D PhoneSwitcher: Removed DcRequest, size: 7
01-10 17:58:01.316   654   654 D TelephonyNetworkFactory[0]: onReleaseNetworkFor NetworkRequest [ TRACK_DEFAULT id=17, [ Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED Uid: 1001 AdministratorUids: [] RequestorUid: 1001 RequestorPackageName: com.android.phone] ] applied false
01-10 17:58:01.335   654   872 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:01.343   654   872 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:02.384  1220  1220 D RILD    : **RIL Daemon Started**
01-10 17:58:02.385  1220  1220 D RILD    : **RILd param count=1**
01-10 17:58:02.400  1220  1220 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:02.401  1220  1220 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:02.666  1220  1220 D RILD    : RIL_Init rilInit completed
01-10 17:58:02.666  1220  1220 I RILC    : SIM_COUNT: 1
01-10 17:58:02.666  1220  1220 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:02.666  1220  1220 D RILD    : RIL_Init RIL_register completed
01-10 17:58:02.666  1220  1220 D RILD    : RIL_register_socket completed
01-10 17:58:02.846   364   944 D TelephonyRegistry: listen oscl: mHasNotifySubscriptionInfoChangedOccurred==false no callback
01-10 17:58:07.377  1566  1566 D RILD    : **RIL Daemon Started**
01-10 17:58:07.378  1566  1566 D RILD    : **RILd param count=1**
01-10 17:58:07.386  1566  1566 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:07.386  1566  1566 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:07.641  1566  1566 D RILD    : RIL_Init rilInit completed
01-10 17:58:07.641  1566  1566 I RILC    : SIM_COUNT: 1
01-10 17:58:07.641  1566  1566 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:07.641  1566  1566 D RILD    : RIL_Init RIL_register completed
01-10 17:58:07.641  1566  1566 D RILD    : RIL_register_socket completed
01-10 17:58:12.382  1586  1586 D RILD    : **RIL Daemon Started**
01-10 17:58:12.383  1586  1586 D RILD    : **RILd param count=1**
01-10 17:58:12.390  1586  1586 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:12.391  1586  1586 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:12.647  1586  1586 D RILD    : RIL_Init rilInit completed
01-10 17:58:12.647  1586  1586 I RILC    : SIM_COUNT: 1
01-10 17:58:12.647  1586  1586 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:12.647  1586  1586 D RILD    : RIL_Init RIL_register completed
01-10 17:58:12.647  1586  1586 D RILD    : RIL_register_socket completed
01-10 17:58:14.707   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:58:14.708   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:58:14.712   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:58:14.712   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:58:14.713   654   654 D NetworkTypeController: [0] LegacyState: process EVENT_PHYSICAL_CHANNEL_CONFIG_NOTIF_CHANGED
01-10 17:58:14.714   654   654 D NetworkTypeController: [0] DefaultState: process EVENT_PHYSICAL_CHANNEL_CONFIG_NOTIF_CHANGED
01-10 17:58:14.714   654   654 D NetworkTypeController: [0] mIsPhysicalChannelConfigOn changed to: false
01-10 17:58:14.823   654   654 D DCT-C-0 : screen off
01-10 17:58:14.824   654   654 D DCT-C-0 : stopNetStatPoll
01-10 17:58:26.921  1617  1617 D RILD    : **RIL Daemon Started**
01-10 17:58:26.921  1617  1617 D RILD    : **RILd param count=1**
01-10 17:58:26.937  1617  1617 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:26.938  1617  1617 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:26.981   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:58:26.982   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:58:26.982   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:58:26.982   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:58:26.983   654   654 E RILJ    : getRadioProxy: mRadioProxy for slot1 is disabled [PHONE0]
01-10 17:58:26.984   654   654 E RILJ    : getRadioProxy: mRadioProxy == null [PHONE0]
01-10 17:58:26.984   654   654 D NetworkTypeController: [0] LegacyState: process EVENT_PHYSICAL_CHANNEL_CONFIG_NOTIF_CHANGED
01-10 17:58:26.985   654   654 D NetworkTypeController: [0] DefaultState: process EVENT_PHYSICAL_CHANNEL_CONFIG_NOTIF_CHANGED
01-10 17:58:26.985   654   654 D NetworkTypeController: [0] mIsPhysicalChannelConfigOn changed to: true
01-10 17:58:27.045   654   654 D DCT-C-0 : screen on
01-10 17:58:27.046   654   654 D DCT-C-0 : stopNetStatPoll
01-10 17:58:27.193  1617  1617 D RILD    : RIL_Init rilInit completed
01-10 17:58:27.193  1617  1617 I RILC    : SIM_COUNT: 1
01-10 17:58:27.193  1617  1617 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:27.193  1617  1617 D RILD    : RIL_Init RIL_register completed
01-10 17:58:27.193  1617  1617 D RILD    : RIL_register_socket completed
01-10 17:58:30.046   654   673 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:30.054   654   673 D SubscriptionController: [getSlotIndex]- subId invalid
01-10 17:58:31.913  1746  1746 D RILD    : **RIL Daemon Started**
01-10 17:58:31.914  1746  1746 D RILD    : **RILd param count=1**
01-10 17:58:31.920  1746  1746 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:31.920  1746  1746 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:32.181  1746  1746 D RILD    : RIL_Init rilInit completed
01-10 17:58:32.182  1746  1746 I RILC    : SIM_COUNT: 1
01-10 17:58:32.182  1746  1746 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:32.182  1746  1746 D RILD    : RIL_Init RIL_register completed
01-10 17:58:32.182  1746  1746 D RILD    : RIL_register_socket completed
01-10 17:58:36.934  1758  1758 D RILD    : **RIL Daemon Started**
01-10 17:58:36.934  1758  1758 D RILD    : **RILd param count=1**
01-10 17:58:36.941  1758  1758 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:36.941  1758  1758 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:37.201  1758  1758 D RILD    : RIL_Init rilInit completed
01-10 17:58:37.202  1758  1758 I RILC    : SIM_COUNT: 1
01-10 17:58:37.202  1758  1758 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:37.202  1758  1758 D RILD    : RIL_Init RIL_register completed
01-10 17:58:37.202  1758  1758 D RILD    : RIL_register_socket completed
01-10 17:58:41.953  1772  1772 D RILD    : **RIL Daemon Started**
01-10 17:58:41.953  1772  1772 D RILD    : **RILd param count=1**
01-10 17:58:41.959  1772  1772 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:41.959  1772  1772 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:42.218  1772  1772 D RILD    : RIL_Init rilInit completed
01-10 17:58:42.219  1772  1772 I RILC    : SIM_COUNT: 1
01-10 17:58:42.219  1772  1772 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:42.219  1772  1772 D RILD    : RIL_Init RIL_register completed
01-10 17:58:42.219  1772  1772 D RILD    : RIL_register_socket completed
01-10 17:58:46.954  1783  1783 D RILD    : **RIL Daemon Started**
01-10 17:58:46.954  1783  1783 D RILD    : **RILd param count=1**
01-10 17:58:46.961  1783  1783 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:46.961  1783  1783 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:47.221  1783  1783 D RILD    : RIL_Init rilInit completed
01-10 17:58:47.221  1783  1783 I RILC    : SIM_COUNT: 1
01-10 17:58:47.221  1783  1783 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:47.221  1783  1783 D RILD    : RIL_Init RIL_register completed
01-10 17:58:47.221  1783  1783 D RILD    : RIL_register_socket completed
01-10 17:58:51.957  1795  1795 D RILD    : **RIL Daemon Started**
01-10 17:58:51.957  1795  1795 D RILD    : **RILd param count=1**
01-10 17:58:51.966  1795  1795 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:51.966  1795  1795 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:52.220  1795  1795 D RILD    : RIL_Init rilInit completed
01-10 17:58:52.221  1795  1795 I RILC    : SIM_COUNT: 1
01-10 17:58:52.221  1795  1795 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:52.221  1795  1795 D RILD    : RIL_Init RIL_register completed
01-10 17:58:52.221  1795  1795 D RILD    : RIL_register_socket completed
01-10 17:58:56.974  1807  1807 D RILD    : **RIL Daemon Started**
01-10 17:58:56.974  1807  1807 D RILD    : **RILd param count=1**
01-10 17:58:56.981  1807  1807 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:58:56.981  1807  1807 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:58:57.239  1807  1807 D RILD    : RIL_Init rilInit completed
01-10 17:58:57.240  1807  1807 I RILC    : SIM_COUNT: 1
01-10 17:58:57.240  1807  1807 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:58:57.240  1807  1807 D RILD    : RIL_Init RIL_register completed
01-10 17:58:57.240  1807  1807 D RILD    : RIL_register_socket completed
01-10 17:59:01.980  1818  1818 D RILD    : **RIL Daemon Started**
01-10 17:59:01.980  1818  1818 D RILD    : **RILd param count=1**
01-10 17:59:01.987  1818  1818 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:59:01.987  1818  1818 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:59:02.247  1818  1818 D RILD    : RIL_Init rilInit completed
01-10 17:59:02.247  1818  1818 I RILC    : SIM_COUNT: 1
01-10 17:59:02.247  1818  1818 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:59:02.247  1818  1818 D RILD    : RIL_Init RIL_register completed
01-10 17:59:02.247  1818  1818 D RILD    : RIL_register_socket completed
01-10 17:59:06.996  1829  1829 D RILD    : **RIL Daemon Started**
01-10 17:59:06.996  1829  1829 D RILD    : **RILd param count=1**
01-10 17:59:07.003  1829  1829 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/hw/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-10 17:59:07.003  1829  1829 D RILD    : RIL_Init argc = 5 clientId = 0
01-10 17:59:07.261  1829  1829 D RILD    : RIL_Init rilInit completed
01-10 17:59:07.261  1829  1829 I RILC    : SIM_COUNT: 1
01-10 17:59:07.261  1829  1829 E RILC    : RIL_register: RIL_RadioFunctions * null
01-10 17:59:07.261  1829  1829 D RILD    : RIL_Init RIL_register completed
01-10 17:59:07.262  1829  1829 D RILD    : RIL_register_socket completed

I've not yet pushed all the patches (in my GNUtoo namespace).

That was obtained by doing an eng build and running the following commands on the serial port:

su
dmesg -n1
logcat -b radio

The UART is needed because:
  • As I understand, this kernel rebase on top of v5.10-rc2, completely breaks USB (and so adb) when the HSIC bus is reset.
  • We don't have enough permissions to get the radio logs on the device
Actions #11

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

TODO:
  • Double check the libsamsung-ril path (/system/vendor/lib/hw/libsamsung-ril.so vs /system/vendor/lib/libsamsung-ril.so)
Actions #12

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

It doesn't print anything because ALOG* has been replaced by RLOG*. In libsamsung-ril we have:

samsung-ril.h:#define RIL_LOGD                          ALOGD

Replacing the prints with RLOGD works. After fixing that the next step would be to fix the RIL_RadioFunctions being NULL and check if all the data structures from samsung-ril.h are fine.

Actions #13

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

With the replicant-11-i9300-modem, and an UART adapter and the following commands:

su
stop ril-daemon
echo 0 > /sys/devices/platform/xmm6262/modem_power
echo 0 > /sys/devices/platform/soc/12580000.ehci/ehci_power
/system/bin/xmm6262_boot0.sh
logcat -b radio -c
/vendor/bin/hw/rild &
logcat -b radio

I get:

console:/ # /vendor/bin/hw/rild &
[1] 1526
console:/ # [  176.794361] gpiohack xmm6262: new state: 0
[  176.847644] gpiohack xmm6262: link active? 0
[  176.851227] gpiohack xmm6262: new state: 1
generic_boot: xm[  177.119863] gpiohack xmm6262: pda active => 1
[  177.124380] exynos-ehci 12580000.ehci: Powering on EHCI
[  177.130015] exynos-ehci 12580000.ehci: EHCI Host Controller
[  177.134538] exynos-ehci 12580000.ehci: new USB bus registered, assigned bus number 1
m626_kernel_linux_modem_power(NULL, 1) = 0[  177.146405] exynos-ehci 12580000.ehci: irq 66, io mem 0x12580000

[  177.178945] exynos-ehci 12580000.ehci: USB 2.0 started, EHCI 1.00
[  177.184235] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[  177.192020] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[  177.199127] usb usb1: Product: EHCI Host Controller
[  177.203941] usb usb1: Manufacturer: Linux 5.10.0-rc2+ ehci_hcd
[  177.209848] usb usb1: SerialNumber: 12580000.ehci
l[  177.216315] hub 1-0:1.0: USB hub found
[  177.218630] hub 1-0:1.0: 3 ports detected
[  177.274142] gpiohack xmm6262: link active? 1
generic_boot: xmm626_kernel_linux_modem_hci_power(1) = 0
Bus 001 Device 001: ID 1d6b:0002
og[  177.589041] usb 1-2: new high-speed USB device number 2 using exynos-ehci
c[  177.790872] usb 1-2: config 1 interface 0 altsetting 0 endpoint 0x81 has an invalid bInterval 255, changing to 11
[  177.799954] usb 1-2: New USB device found, idVendor=058b, idProduct=0041, bcdDevice= 0.00
[  177.807872] usb 1-2: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[  177.815554] type=1400 audit(1611058657.180:356): avc: denied { mknod } for comm="kdevtmpfs" capability=27 scontext=u:r:kernel:s0 tcontext=u:r:kernel:s0 tclass=capability permissive=1
[  177.831669] xmm6262_boot 1-2:1.0: Loaded XMM6262 boot serial device!
aBus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
t -b radio
[  179.436363] logd: logdr: UID=0 GID=0 PID=1530 b tail=0 logMask=2 pid=0 start=0ns timeout=0ns
--------- beginning of radio
01-19 12:17:36.157  1526  1526 D RILD    : **RIL Daemon Started**
01-19 12:17:36.157  1526  1526 D RILD    : **RILd param count=1**
01-19 12:17:36.165  1526  1526 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-19 12:17:36.165  1526  1526 D RILD    : RIL_Init argc = 5 clientId = 0
01-19 12:17:36.165  1526  1526 D RIL     : libsamsung-ril: Started from RIL_Init
01-19 12:17:36.165  1526  1526 D RIL     : Created IPC FMT client
01-19 12:17:36.165  1526  1526 D RIL     : Created IPC RFS client
01-19 12:17:36.165  1526  1526 D RIL     : Created SRS client
01-19 12:17:36.165  1526  1526 D RIL-IPC : Starting generic modem boot
01-19 12:17:36.165  1526  1526 D RIL-IPC : Mapped modem image data to memory
01-19 12:17:36.222  1526  1526 D RIL-IPC : Turned the modem off
01-19 12:17:36.648  1526  1526 D RIL-IPC : Turned the modem on
01-19 12:17:37.203  1526  1526 D RIL-IPC : Opened modem boot device
01-19 12:17:37.252  1526  1526 D RIL-IPC : Wrote ATAT in ASCII
01-19 12:17:37.353  1526  1526 D RIL-IPC : Read chip id (0x16)
01-19 12:17:37.353  1526  1526 D RIL-IPC : Wrote PSI header
01-19 12:17:37.356  1526  1526 D RIL-IPC : Wrote PSI, CRC is 0xc8
01-19 12:17:37.356  1526  1526 D RIL-IPC : Wrote PSI CRC (0xc8)
01-19 12:17:37.457  1526  1526 D RIL-IPC : Read PSI CRC ACK
01-19 12:17:37.457  1526  1526 D RIL-IPC : Read PSI ACK
01-19 12:17:37.457  1526  1526 D RIL-IPC : Sent XMM626 HSIC PSI
01-19 12:17:37.457  1526  1526 D RIL-IPC : Wrote EBL size
01-19 12:17:37.468  1526  1526 D RIL-IPC : Wrote EBL, CRC is 0xb5
01-19 12:17:37.468  1526  1526 D RIL-IPC : Wrote EBL CRC (0xb5)
01-19 12:17:38.470  1526  1526 D RIL-IPC : Sent XMM626 HSIC EBL
01-19 12:17:38.471  1526  1526 D RIL-IPC : Read port config
01-19 12:17:39.472  1526  1526 D RIL-IPC : Sent XMM626 HSIC port config
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-19 12:17:40.539  1526  1526 D RIL-IPC : Sent XMM626 HSIC SEC start
01-19 12:17:41.739  1526  1526 D RIL-IPC : Sent XMM626 HSIC firmware
Bus 001 Device 001: ID 1d6b:0002
Bus 001 De[  182.412890] SELinux:  Context u:object_r:efs_device_file:s0 is not valid (left unmapped).
vice 002: ID 058b:0041
01-19 12:17:41.784  1526  1526 D RIL-IPC : Checked nv_data path
01-19 12:17:41.792  1526  1526 D RIL-IPC : Checked nv_data md5 path
01-19 12:17:41.838  1526  1526 D RIL-IPC : Calculated nv_data md5: 2ddb7fb2b0f7078c5d7c4647cfa885fc
01-19 12:17:41.839  1526  1526 D RIL-IPC : Read nv_data md5: 2ddb7fb2b0f7078c5d7c4647cfa885fc
01-19 12:17:41.839  1526  1526 D RIL-IPC : Checked nv_data backup path
01-19 12:17:41.847  1526  1526 D RIL-IPC : Loaded nv_data
01-19 12:17:42.888  1526  1526 D RIL-IPC : Sent XMM626 HSIC nv_data
01-19 12:17:43.891  1526  1526 D RIL-IPC : Sent XMM626 HSIC SEC end
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-19 12:17:43.953  1526  1526 D RIL-IPC : Sent XMM626 HSIC HW reset
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
[  184.714923] xmm6262_boot 1-2:1.0: nonzero bulk read status: -71
[  184.770863] gpiohack xmm6262: phone_active: cp_reset=1, phone_active=1, cp_dump=0
[  184.776914] gpiohack xmm6262: BOOTING
01-19 12:17:49.298  1526  1526 D RIL-IPC : Waited for host wake
Bus 001 Device 001: ID 1d6b:00[  189.989947] exynos-ehci 12580000.ehci: Powering off EHCI
[  189.994853] exynos-ehci 12580000.ehci: remove, state 1
[  190.000015] usb usb1: USB disconnect, device number 1
[  190.005009] usb 1-2: USB disconnect, device number 2
02
Bus 001 Device 002: ID 058b:0041
[  190.015302] exynos-ehci 12580000.ehci: USB bus 1 deregistered
[  190.070700] gpiohack xmm6262: link active? 0
01-19 12:17:49.445  1526  1526 D RIL-IPC : Turned off the modem
01-19 12:17:54.502  1526  1526 D RIL-IPC : Waited for host wake
[  195.195392] gpiohack xmm6262: pda active => 1
[  195.198403] exynos-ehci 12580000.ehci: Powering on EHCI
[  195.203931] exynos-ehci 12580000.ehci: EHCI Host Controller
[  195.209087] exynos-ehci 12580000.ehci: new USB bus registered, assigned bus number 1
[  195.217443] exynos-ehci 12580000.ehci: irq 66, io mem 0x12580000
[  195.248979] exynos-ehci 12580000.ehci: USB 2.0 started, EHCI 1.00
[  195.254513] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[  195.262069] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[  195.269207] usb usb1: Product: EHCI Host Controller
[  195.274011] usb usb1: Manufacturer: Linux 5.10.0-rc2+ ehci_hcd
[  195.279881] usb usb1: SerialNumber: 12580000.ehci
[  195.286471] hub 1-0:1.0: USB hub found
[  195.288807] hub 1-0:1.0: 3 ports detected
[  195.344683] gpiohack xmm6262: link active? 1
01-19 12:17:54.719  1526  1526 D RIL-IPC : Turned the modem on
Bus 001 Device 001: ID 1d6b:0002
01-19 12:17:54.776  1526  1526 D RIL-IPC : Wait for the modem to come up again
[  195.659105] usb 1-2: new high-speed USB device number 2 using exynos-ehci
[  195.866728] usb 1-2: New USB device found, idVendor=1519, idProduct=0020, bcdDevice=12.74
[  195.873632] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  195.880701] usb 1-2: Product: HSIC Device
[  195.884593] usb 1-2: Manufacturer: Comneon
[  195.888707] usb 1-2: SerialNumber: 0123456789
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 1519:0020
01-19 12:18:04.840  1526  1526 D RIL-IPC : generic_boot complete
ENTER xmm626_kernel_linux_modem_open
xmm626_kernel_linux_modem_open[  212.524616] samsung_ipc modem: Processed 11 bytes
[  212.528632] samsung_ipc modem: Processed 38 bytes
[  212.533307] samsung_ipc modem: Processed 40 bytes
[  212.537976] samsung_ipc modem: Processed 21 bytes
[  212.542687] samsung_ipc modem: Processed 22 bytes
[  212.547378] samsung_ipc modem: Processed 89 bytes
: type: 0
ENTER xmm626_kernel_linux_modem_open
01-19 12:18:11.894  1526  1526 D RIL     :[  212.560966] type=1400 audit(1611058691.930:357): avc: denied { confidentiality } for comm="rild" lockdown_reason="use of tracefs" scontext=u:r:su:s0 tcontext=u:r:su:s0 tclass=lockdown permissive=1
 Opened IPC FMT client
01-19 12:18:11.895  1526  1526 D RIL     : Started IPC FMT client loop
xmm626_kernel_linux_modem_open: type: 1
01-19 12:18:11.925  1526  1526 D RIL     : Opened IPC RFS client
01-19 12:18:11.926  1526  1526 D RIL     : Started IPC RFS client loop
01-19 12:18:11.926  1526  1542 E RIL     : IPC RFS client loop failed
01-19 12:18:11.926  1526  1526 D RIL-SRS : Started SRS server loop
01-19 12:18:11.927  1526  1543 E RIL-SRS : SRS client is not available
01-19 12:18:11.927  1526  1526 D RIL     : Opened SRS client
01-19 12:18:11.927  1526  1543 E RIL-SRS : SRS server loop failed
01-19 12:18:11.927  1526  1526 D RIL     : Started SRS client loop
01-19 12:18:11.928  1526  1526 D RILD    : RIL_Init rilInit completed
01-19 12:18:11.928  1526  1541 E RIL     : IPC FMT client loop failed
01-19 12:18:11.928  1526  1526 I RILC    : SIM_COUNT: 1
01-19 12:18:11.928  1526  1526 E RILC    : RIL_register: RIL version 12
01-19 12:18:11.928  1526  1526 I RILC    : s_registerCalled flag set, 1
01-19 12:18:11.929  1526  1526 D RILC    : registerService: starting android::hardware::radio::V1_1::IRadio slot1
01-19 12:18:11.942  1526  1526 I RILC    : RILHIDL called registerService
01-19 12:18:11.942  1526  1526 D RILD    : RIL_Init RIL_register completed
01-19 12:18:11.942  1526  1526 D RILD    : RIL_register_socket completed
01-19 12:18:11.976  1526  1542 E RIL-IPC : Powering off IPC RFS client failed
01-19 12:18:11.977  1526  1542 E RIL     : Closing IPC RFS client failed
ENTER xmm626_kernel_linux_modem_open
01-19 12:18:11.978  1526  1541 D RIL     : Closed IPC FMT client
xmm626_kernel_linux_modem_open: type: 0
01-19 12:18:12.009  1526  1541 D RIL     : Updating RIL radio state to 0
01-19 12:18:12.015  1526  1541 E RILC    : radioStateChangedInd: radioService[0]->mRadioIndication == NULL
01-19 12:18:12.015  1526  1541 E RILC    : callStateChangedInd: radioService[0]->mRadioIndication == NULL
01-19 12:18:12.015  1526  1541 E RILC    : networkStateChangedInd: radioService[0]->mRadioIndication == NULL
01-19 12:18:12.016  1526  1541 E RILC    : dataCallListChangedInd: radioService[0]->mRadioIndication == NULL
01-19 12:18:12.016  1526  1541 E RILC    : simStatusChangedInd: radioService[0]->mRadioIndication == NULL
01-19 12:18:12.016  1526  1541 D RIL     : Opened IPC FMT client
01-19 12:18:12.027  1526  1542 E RIL-IPC : Powering off IPC RFS client failed
01-19 12:18:12.027  1526  1542 E RIL     : Closing IPC RFS client failed
01-19 12:18:12.078  1526  1542 E RIL-IPC : Powering off IPC RFS client failed
01-19 12:18:12.078  1526  1542 E RIL     : Closing IPC RFS client failed
01-19 12:18:12.129  1526  1542 E RIL-IPC : Powering off IPC RFS client failed
01-19 12:18:12.129  1526  1542 E RIL     : Closing IPC RFS client failed
01-19 12:18:12.129  1526  1542 E RIL-IPC : Powering off IPC RFS client failed
01-19 12:18:12.129  1526  1542 E RIL     : Closing IPC RFS client failed
01-19 12:18:12.130  1526  1542 D RIL     : Destroyed IPC RFS client
01-19 12:18:12.130  1526  1542 D RIL     : Stopped IPC RFS client loop
[  213.114980] type=1400 audit(1611058692.480:358): avc: denied { ioctl } for comm="android.ui" path="/dev/dri/renderD129" dev="tmpfs" ino=239 ioctlcmd=0x6444 scontext=u:r:system_server:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  213.152577] type=1400 audit(1611058692.520:359): avc: denied { ioctl } for comm="android.ui" path="/dev/dri/renderD129" dev="tmpfs" ino=239 ioctlcmd=0x6444 scontext=u:r:system_server:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  213.376501] wm8994-codec wm8994-codec: FIFO error
[  214.357230] type=1400 audit(1611058693.720:360): avc: denied { ioctl } for comm="RenderThread" path="/dev/dri/renderD129" dev="tmpfs" ino=239 ioctlcmd=0x6409 scontext=u:r:priv_app:s0:c512,c768 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1 app=com.android.launcher3
[  214.396113] type=1400 audit(1611058693.760:361): avc: denied { ioctl } for comm="allocator@2.0-s" path="/dev/dri/card0" dev="tmpfs" ino=328 ioctlcmd=0x64b2 scontext=u:r:hal_graphics_allocator_default:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  214.466225] type=1400 audit(1611058693.830:362): avc: denied { map } for comm="GrallocUploadTh" path="/dev/dri/renderD129" dev="tmpfs" ino=239 scontext=u:r:priv_app:s0:c512,c768 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1 app=com.android.launcher3
[  214.508578] type=1400 audit(1611058693.830:363): avc: denied { read write } for comm="GrallocUploadTh" path="/dev/dri/renderD129" dev="tmpfs" ino=239 scontext=u:r:priv_app:s0:c512,c768 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1 app=com.android.launcher3
[  214.795675] type=1400 audit(1611058694.160:364): avc: denied { confidentiality } for comm="main" lockdown_reason="use of tracefs" scontext=u:r:zygote:s0 tcontext=u:r:zygote:s0 tclass=lockdown permissive=1
[  214.848131] type=1400 audit(1611058694.210:365): avc: denied { ioctl } for comm="RenderThread" path="/dev/dri/renderD129" dev="tmpfs" ino=239 ioctlcmd=0x64c1 scontext=u:r:platform_app:s0:c512,c768 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1 app=com.android.systemui
[  214.878107] type=1400 audit(1611058694.210:367): avc: denied { ioctl } for comm="composer@2.1-se" path="/dev/dri/card0" dev="tmpfs" ino=328 ioctlcmd=0x64af scontext=u:r:hal_graphics_composer_default:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  215.064110] audit: audit_lost=58 audit_rate_limit=5 audit_backlog_limit=64
[  215.069681] audit: rate limit exceeded
01-19 12:18:14.720   622   648 D SubscriptionController: [getSlotIndex]- subId invalid
[  219.480169] type=1400 audit(1611058698.840:372): avc: denied { ioctl } for comm="GrallocUploadTh" path="/dev/dri/renderD129" dev="tmpfs" ino=239 ioctlcmd=0x64c0 scontext=u:r:priv_app:s0:c512,c768 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1 app=com.android.launcher3

[  252.439493] type=1400 audit(1611058731.800:373): avc: denied { read } for comm="storaged" name="stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  252.457872] type=1400 audit(1611058731.800:374): avc: denied { open } for comm="storaged" path="/sys/devices/platform/soc/12530000.sdhci/mmc_host/mmc0/mmc0:5048/block/mmcblk0/stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  252.482615] type=1400 audit(1611058731.800:375): avc: denied { getattr } for comm="storaged" path="/sys/devices/platform/soc/12530000.sdhci/mmc_host/mmc0/mmc0:5048/block/mmcblk0/stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  255.951797] type=1400 audit(1611058735.320:376): avc: denied { read } for comm="health@2.1-serv" name="present" dev="sysfs" ino=40336 scontext=u:r:hal_health_default:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  255.965336] healthd: battery l=94 v=3917 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=9 chg=
[  255.970462] type=1400 audit(1611058735.320:377): avc: denied { open } for comm="health@2.1-serv" path="/sys/devices/platform/i2c-gpio-1/i2c-11/11-0066/max77693-charger/power_supply/max77693-charger/present" dev="sysfs" ino=40336 scontext=u:r:hal_health_default:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  256.006597] type=1400 audit(1611058735.320:378): avc: denied { getattr } for comm="health@2.1-serv" path="/sys/devices/platform/i2c-gpio-1/i2c-11/11-0066/max77693-charger/power_supply/max77693-charger/present" dev="sysfs" ino=40336 scontext=u:r:hal_health_default:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  260.687965] type=1400 audit(1611058740.050:379): avc: denied { map } for comm="surfaceflinger" path="/dev/dri/renderD129" dev="tmpfs" ino=239 scontext=u:r:surfaceflinger:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  260.707285] type=1400 audit(1611058740.050:380): avc: denied { read write } for comm="surfaceflinger" path="/dev/dri/renderD129" dev="tmpfs" ino=239 scontext=u:r:surfaceflinger:s0 tcontext=u:object_r:device:s0 tclass=chr_file permissive=1
[  316.052663] healthd: battery l=94 v=3907 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=9 chg=
[  372.442549] type=1400 audit(1611058851.810:381): avc: denied { read } for comm="storaged" name="stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  372.459549] type=1400 audit(1611058851.810:382): avc: denied { open } for comm="storaged" path="/sys/devices/platform/soc/12530000.sdhci/mmc_host/mmc0/mmc0:5048/block/mmcblk0/stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  372.484107] type=1400 audit(1611058851.810:383): avc: denied { getattr } for comm="storaged" path="/sys/devices/platform/soc/12530000.sdhci/mmc_host/mmc0/mmc0:5048/block/mmcblk0/stat" dev="sysfs" ino=38360 scontext=u:r:storaged:s0 tcontext=u:object_r:sysfs:s0 tclass=file permissive=1
[  376.136324] healthd: battery l=94 v=3900 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=9 chg=
[  436.224750] healthd: battery l=94 v=3898 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=10 chg=
[  496.313330] healthd: battery l=94 v=3893 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=10 chg=
[  556.400655] healthd: battery l=94 v=3893 t=22.0 h=2 st=3 c=2097 fc=1056500 cc=11 chg=

Beside the known TODO like creating the nodes created by /system/bin/xmm6262_boot0.sh automatically and maybe some selinux rules for rild too, we still have some more integration to do as the IPC/RFS/SRS clients end up failing.

Actions #14

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

Here's the new commands I use:

su
stop ril-daemon
echo 0 > /sys/devices/platform/xmm6262/modem_power
echo 0 > /sys/devices/platform/soc/12580000.ehci/ehci_power
/system/bin/xmm6262_boot0
logcat -b radio -c
dd if=/sdcard/RADIO.img of=/dev/block/mmcblk2p7
sync
/vendor/bin/hw/rild &
logcat -b radio

For some reasons I'm also having corruption from the RADIO.img image.
So I need to restore a backup for the boot to succeed.

mmcblk2p7 is not supposed to be modified by the modem or libsamsung-ril / libsamsung-ipc so I still need to look at why it happens.

Actions #15

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

And here's the new log after the bootstrap:

ENTER xmm626_kernel_linux_modem_open
01-20 04:17:55.939  1675  1675 D RIL     : Opened IPC FMT client
01-20 04:17:55.939  1675  1675 D RIL     : Started IPC FMT client loop
01-20 04:17:55.945  1675  1692 E RIL     : eventfd_recv: eventfd_read error 11: Try again
01-20 04:17:55.945  1675  1692 E RIL-IPC : Receiving IPC FMT data with eventfd_recv failed with error -1
xmm626_kernel_linux_modem_open: type: 1
01-20 04:17:55.970  1675  1675 D RIL     : Opened IPC RFS client
01-20 04:17:55.970  1675  1675 D RIL     : Started IPC RFS client loop
01-20 04:17:55.971  1675  1693 E RIL     : eventfd_recv: eventfd_read error 11: Try again
01-20 04:17:55.971  1675  1693 E RIL-IPC : Receiving IPC RFS data with eventfd_recv failed with error -1
01-20 04:17:55.971  1675  1693 E RIL     : IPC RFS client loop failed with error -1
01-20 04:17:55.971  1675  1694 E RIL-SRS : SRS client is not available
01-20 04:17:55.972  1675  1694 E RIL-SRS : SRS server loop failed
01-20 04:17:55.971  1675  1675 D RIL-SRS : Started SRS server loop
01-20 04:17:55.972  1675  1675 D RIL     : Opened SRS client
01-20 04:17:55.973  1675  1675 D RIL     : Started SRS client loop
01-20 04:17:55.973  1675  1675 D RILD    : RIL_Init rilInit completed
01-20 04:17:55.973  1675  1692 E RIL     : IPC FMT client loop failed with error -1
01-20 04:17:55.973  1675  1675 I RILC    : SIM_COUNT: 1
01-20 04:17:55.974  1675  1675 E RILC    : RIL_register: RIL version 12
01-20 04:17:55.974  1675  1675 I RILC    : s_registerCalled flag set, 1
01-20 04:17:55.975  1675  1675 D RILC    : registerService: starting android::hardware::radio::V1_1::IRadio slot1
01-20 04:17:55.986  1675  1675 I RILC    : RILHIDL called registerService
01-20 04:17:55.987  1675  1675 D RILD    : RIL_Init RIL_register completed
01-20 04:17:55.987  1675  1675 D RILD    : RIL_register_socket completed
01-20 04:17:56.021  1675  1693 E RIL-IPC : Powering off IPC RFS client failed
01-20 04:17:56.022  1675  1693 E RIL     : Closing IPC RFS client failed
ENTER xmm626_kernel_linux_modem_open
01-20 04:17:56.024  1675  1692 D RIL     : Closed IPC FMT client
xmm626_kernel_linux_modem_open: type: 0
01-20 04:17:56.054  1675  1692 D RIL     : Updating RIL radio state to 0
01-20 04:17:56.059  1675  1692 E RILC    : radioStateChangedInd: radioService[0]->mRadioIndication == NULL
01-20 04:17:56.059  1675  1692 E RILC    : callStateChangedInd: radioService[0]->mRadioIndication == NULL
01-20 04:17:56.059  1675  1692 E RILC    : networkStateChangedInd: radioService[0]->mRadioIndication == NULL
01-20 04:17:56.060  1675  1692 E RILC    : dataCallListChangedInd: radioService[0]->mRadioIndication == NULL
01-20 04:17:56.060  1675  1692 E RILC    : simStatusChangedInd: radioService[0]->mRadioIndication == NULL
01-20 04:17:56.060  1675  1692 D RIL     : Opened IPC FMT client
01-20 04:17:56.072  1675  1693 E RIL-IPC : Powering off IPC RFS client failed
01-20 04:17:56.072  1675  1693 E RIL     : Closing IPC RFS client failed
01-20 04:17:56.123  1675  1693 E RIL-IPC : Powering off IPC RFS client failed
01-20 04:17:56.123  1675  1693 E RIL     : Closing IPC RFS client failed
01-20 04:17:56.173  1675  1693 E RIL-IPC : Powering off IPC RFS client failed
01-20 04:17:56.174  1675  1693 E RIL     : Closing IPC RFS client failed
01-20 04:17:56.174  1675  1693 E RIL-IPC : Powering off IPC RFS client failed
01-20 04:17:56.174  1675  1693 E RIL     : Closing IPC RFS client failed
01-20 04:17:56.175  1675  1693 D RIL     : Destroyed IPC RFS client
01-20 04:17:56.175  1675  1693 D RIL     : Stopped IPC RFS client loop
[  520.598288] healthd: battery l=74 v=3557 t=22.0 h=2 st=3 c=2097 fc=1000000 cc=8 chg=
[  580.652151] healthd: battery l=74 v=3548 t=22.0 h=2 st=3 c=2097 fc=1000000 cc=8 chg=

[  608.333382] healthd: battery l=74 v=3543 t=22.0 h=2 st=3 c=2097 fc=1000000 cc=9 chg=

Actions #16

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

The error is EAGAIN.

We probably need to standardize more the libsamsung-ipc API as this stuff is exported as-is from the kernel without any abstraction in between.

The issue is that depending on the device and kernel, the upper library (libsamsung-ril, oFono, etc) might need to handle things differently.

However doing too much in libsamsung-ipc is not a good idea either as we want to be able to use it in a wide variety of frameworks, OS and so on. So it should be up to the upper library (like libsamsung-ril) to use the threading / blocking model that suits its needs.

Another option would be to add a compilation option to only support the upstream kernel: this way the kernel won't do strange things and we can be sure of the API.

Actions #17

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

Here's the current log:

--------- beginning of radio
01-20 04:55:32.756   618   641 D SubscriptionController: [getActiveSubscriptionInfoForSimSlotIndex]+ slotIndex=0 subId=null
01-20 04:57:25.924  1836  1836 D RILD    : **RIL Daemon Started**
01-20 04:57:25.924  1836  1836 D RILD    : **RILd param count=1**
01-20 04:57:25.933  1836  1836 W RILD    : RIL_SAP_Init not defined or exported in /system/vendor/lib/libsamsung-ril.so: undefined symbol: RIL_SAP_Init
01-20 04:57:25.933  1836  1836 D RILD    : RIL_Init argc = 5 clientId = 0
01-20 04:57:25.933  1836  1836 D RIL     : libsamsung-ril: Started from RIL_Init
01-20 04:57:25.933  1836  1836 D RIL     : Created IPC FMT client
01-20 04:57:25.933  1836  1836 D RIL     : Created IPC RFS client
01-20 04:57:25.933  1836  1836 D RIL     : Created SRS client
01-20 04:57:25.933  1836  1836 D RIL-IPC : Starting generic modem boot
01-20 04:57:25.934  1836  1836 D RIL-IPC : Mapped modem image data to memory
01-20 04:57:25.985  1836  1836 D RIL-IPC : Turned the modem off
01-20 04:57:26.350  1836  1836 D RIL-IPC : Turned the modem on
01-20 04:57:26.882  1836  1836 D RIL-IPC : Opened modem boot device
01-20 04:57:26.946  1836  1836 D RIL-IPC : Wrote ATAT in ASCII
01-20 04:57:27.047  1836  1836 D RIL-IPC : Read chip id (0x16)
01-20 04:57:27.047  1836  1836 D RIL-IPC : Wrote PSI header
01-20 04:57:27.055  1836  1836 D RIL-IPC : Wrote PSI, CRC is 0xc8
01-20 04:57:27.056  1836  1836 D RIL-IPC : Wrote PSI CRC (0xc8)
01-20 04:57:27.157  1836  1836 D RIL-IPC : Read PSI CRC ACK
01-20 04:57:27.158  1836  1836 D RIL-IPC : Read PSI ACK
01-20 04:57:27.159  1836  1836 D RIL-IPC : Sent XMM626 HSIC PSI
01-20 04:57:27.159  1836  1836 D RIL-IPC : Wrote EBL size
01-20 04:57:27.172  1836  1836 D RIL-IPC : Wrote EBL, CRC is 0xb5
01-20 04:57:27.172  1836  1836 D RIL-IPC : Wrote EBL CRC (0xb5)
01-20 04:57:28.174  1836  1836 D RIL-IPC : Sent XMM626 HSIC EBL
01-20 04:57:28.174  1836  1836 D RIL-IPC : Read port config
01-20 04:57:29.176  1836  1836 D RIL-IPC : Sent XMM626 HSIC port config
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-20 04:57:30.247  1836  1836 D RIL-IPC : Sent XMM626 HSIC SEC start
01-20 04:57:31.404  1836  1836 D RIL-IPC : Sent XMM626 HSIC firmware
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-20 04:57:31.448  1836  1836 D RIL-IPC : Checked nv_data path
01-20 04:57:31.448  1836  1836 D RIL-IPC : Checked nv_data md5 path
01-20 04:57:31.468  1836  1836 D RIL-IPC : Calculated nv_data md5: 2ddb7fb2b0f7078c5d7c4647cfa885fc
01-20 04:57:31.469  1836  1836 D RIL-IPC : Read nv_data md5: 2ddb7fb2b0f7078c5d7c4647cfa885fc
01-20 04:57:31.469  1836  1836 D RIL-IPC : Checked nv_data backup path
01-20 04:57:31.478  1836  1836 D RIL-IPC : Loaded nv_data
01-20 04:57:32.517  1836  1836 D RIL-IPC : Sent XMM626 HSIC nv_data
01-20 04:57:33.520  1836  1836 D RIL-IPC : Sent XMM626 HSIC SEC end
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-20 04:57:33.588  1836  1836 D RIL-IPC : Sent XMM626 HSIC HW reset
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-20 04:57:38.932  1836  1836 D RIL-IPC : Waited for host wake
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 058b:0041
01-20 04:57:39.051  1836  1836 D RIL-IPC : Turned off the modem
01-20 04:57:44.113  1836  1836 D RIL-IPC : Waited for host wake
01-20 04:57:44.257  1836  1836 D RIL-IPC : Turned the modem on
Bus 001 Device 001: ID 1d6b:0002
01-20 04:57:44.317  1836  1836 D RIL-IPC : Wait for the modem to come up again
Bus 001 Device 001: ID 1d6b:0002
Bus 001 Device 002: ID 1519:0020
01-20 04:57:54.373  1836  1836 D RIL-IPC : generic_boot complete
ENTER xmm626_kernel_linux_modem_open
xmm626_kernel_linux_modem_open: type: 0
01-20 04:58:01.433  1836  1836 D RIL     : Opened IPC FMT client
ENTER xmm626_kernel_linux_modem_open
01-20 04:58:01.433  1836  1836 D RIL     : Started IPC FMT client loop
xmm626_kernel_linux_modem_open: type: 1
01-20 04:58:01.464  1836  1836 D RIL     : Opened IPC RFS client
01-20 04:58:01.465  1836  1836 D RIL     : Started IPC RFS client loop
01-20 04:58:01.465  1836  1836 D RIL-SRS : Started SRS server loop
01-20 04:58:01.466  1836  1854 E RIL-SRS : SRS client is not available
01-20 04:58:01.466  1836  1836 D RIL     : Opened SRS client
01-20 04:58:01.466  1836  1854 E RIL-SRS : SRS server loop failed
01-20 04:58:01.466  1836  1836 D RIL     : Started SRS client loop
01-20 04:58:01.468  1836  1836 D RILD    : RIL_Init rilInit completed
01-20 04:58:01.468  1836  1836 I RILC    : SIM_COUNT: 1
01-20 04:58:01.468  1836  1836 E RILC    : RIL_register: RIL version 12
01-20 04:58:01.469  1836  1836 I RILC    : s_registerCalled flag set, 1
01-20 04:58:01.469  1836  1836 D RILC    : registerService: starting android::hardware::radio::V1_1::IRadio slot1
01-20 04:58:01.478  1836  1836 I RILC    : RILHIDL called registerService
01-20 04:58:01.479  1836  1836 D RILD    : RIL_Init RIL_register completed
01-20 04:58:01.479  1836  1836 D RILD    : RIL_register_socket completed

Actions #18

Updated by Denis 'GNUtoo' Carikli almost 4 years ago

I probably need to add more logging to make sure it's not always doing EAGAIN.

Actions #19

Updated by Denis 'GNUtoo' Carikli over 3 years ago

I've written a minimal test with libsamsung-ipc to retrieve the device IMEI.
If I run it multiple times (due to crashes), the test works fine in Replicant 6.0, but not in Replicant 11.

Actions #20

Updated by Denis 'GNUtoo' Carikli over 3 years ago

The thing is that the bootstrap works fine and (few) messages get exchanged but nothing happens. So I need to look why the message aout the IMEI doesn't reach the test utility.

Actions #21

Updated by Denis 'GNUtoo' Carikli over 3 years ago

With the 5.10.0-rc2+ with Parabola I can bring the USB back, it's just de-configured. Re-running my usb-otg.sh scripts that does the setup brings everything back.
Though we'd better find a way to rescan the HSIC bus without forcing the de-configuration of the OTG port as well.
We now have an ugly workaround that needs to be rewritten later on.

Actions #22

Updated by Denis 'GNUtoo' Carikli over 3 years ago

Status with libsamsung-ipc test utilities (both in GNU/Linux and Android) and rild (In replicant 11):
  • The modem boots fine
  • It receive few messages after that
  • It hangs there (it doesn't register to the network etc)
It's not related to the rild integration (which isn't done) as ipc-modem has the same issue:
  • Under Replicant 6 it registers fine to the network
  • Under Parabola1 it doesn't.

1 Here there are no annoying Android security systems, everything runs as root.

Actions #23

Updated by _I3^ RELATIVISM over 3 years ago

  • Type of work C programming, Reverse engineering (no code nor documentation available) added
Actions #24

Updated by _I3^ RELATIVISM over 3 years ago

  • Type of work deleted (Reverse engineering (no code nor documentation available))
Actions

Also available in: Atom PDF