sonyxperiadev / bug_tracker

Empty repository that is used as a bugtracker for Open Devices project
52 stars 13 forks source link

No UART logs from Android -- only from the bootloaders #842

Closed parport0 closed 3 months ago

parport0 commented 3 months ago

Platform: Seine Device: xqau52 Kernel version: 4.14.117-perf+ Android version: Sony/XQ-AU52_EEA/XQ-AU52:10/59.0.A.1.296/059000A001029602956232951:user/release-keys Software binaries version: 59.0.A.1.296

Description For development, I am trying to get Android logs via the UART port as described on https://developer.sony.com/open-source/aosp-on-xperia-open-devices/guides/access-uart-ports/ .

This is my hardware setup: image

Symptoms I get logs from the bootloader, but they get disabled before jumping to Android. These are the last lines I see on the UART:

Shutting Down UEFI Boot Services: 10544 ms
EFI_UdonStop Stop DebugPort for anti-corroding

I thought that this is maybe related to my hardware setup, but moving the PCB in the slot did not yield any results.

Full boot logs:

Click to see the full boot logs ``` UEFI Start [ 2247] - 0x05FC01000 [ 2254] Sec.efi ASLR : ON DEP : ON (RTB) Timer Delta : +5 mS smem_get_addr: SMEM get addr success. smem_type=402, buf_size=2328 and offset = 0x00007848.RAM Entry 0 : Base 0x0000000040000000 Size 0x000000003DD00000 RAM Entry 1 : Base 0x0000000080000000 Size 0x00000000C0000000 UART Buffer size set to 0x8000 Multithread : ON (Lib ver 1.1) CPU Cores : 8 (init 1) Continue booting UEFI on Core 0 CONF File : uefiplatLA.cfg UEFI Ver : 5.0.200304.BOOT.XF.4.0-00203-NICOBARLAZ-1 Build Info : 64b Mar 4 2020 14:55:25 Boot Device : eMMC PROD Mode : FALSE Retail : TRUE - 0x0598B0000 [ 2390] DxeCore.efi Loading DxeCore at 0x00598B0000 EntryPoint=0x00598B1000 HOBLIST address in DXE = 0x596A0018 FV Hob 0x5FC00000 - 0x5FE5FFFF FV Hob 0x59EE6000 - 0x5A4AB6FF FV2 Hob 0x59EE6000 - 0x5A4AB6FF 631008B0-B2D1-410A-8B49-2C5C4D8ECC7E - 9E21FD93-9C72-4C15-8C4B-E77F1DB2D792 - 0x05982E000 [ 2401] XHwresetDxe.efi - 0x059826000 [ 2402] MazeDetDxe.efi - 0x05984F000 [ 2402] EnvDxe.efi smem_get_addr: SMEM get addr success. smem_type=402, buf_size=2328 and offset = 0x00007848. - 0x059845000 [ 2402] RscRtDxe.efi - 0x05983D000 [ 2403] SCHandlerRtDxe.efi - 0x058FE2000 [ 2403] RuntimeDxe.efi - 0x059818000 [ 2403] ArmCpuDxe.efi - 0x05980F000 [ 2405] ArmGicDxe.efi - 0x059808000 [ 2405] MetronomeDxe.efi - 0x059800000 [ 2406] ArmTimerDxe.efi - 0x0597F7000 [ 2406] SmemDxe.efi - 0x0597B8000 [ 2407] DALSys.efi smem_alloc: SMEM allocation success. smem_type=404, buf_size=8192 and offset = 0x000051B0. - 0x0597AF000 [ 2407] HWIODxeDriver.efi - 0x0597A4000 [ 2407] ChipInfo.efi smem_get_addr: SMEM get addr success. smem_type=137, buf_size=248 and offset = 0x00007210. - 0x05979C000 [ 2408] PlatformInfoDxeDriver.efi - 0x059791000 [ 2408] HALIOMMU.efi - 0x059785000 [ 2409] GlinkDxe.efi - 0x059771000 [ 2409] ULogDxe.efi - 0x059758000 [ 2410] NpaDxe.efi - 0x05971E000 [ 2411] ClockDxe.efi DALLOG Device [0x2000070]: HWIO: Unable to find "RM_C_C_TTS/mccin/ipetd - 0x059714000 [ 2424] ShmBridgeDxe.efi - 0x059707000 [ 2424] ScmDxe.efi - 0x0596FC000 [ 2425] DiskIoDxe.efi - 0x0596EF000 [ 2425] PartitionDxe.efi - 0x0596E7000 [ 2426] EnglishDxe.efi - 0x0596DC000 [ 2426] FvSimpleFileSystem.efi - 0x058F70000 [ 2426] SdccDxe.efi - 0x0596C0000 [ 2478] UFSDxe.efi - 0x0596B0000 [ 2479] Fat.efi - 0x058B27000 [ 2479] TzDxe.efi - 0x058A8C000 [ 2483] VariableDxe.efi AppReg Init:35 mS LoadSecureApps: Load app from partition(tzxflattest): Status = 0x0, AppId = 2 - 0x0596A8000 [ 3024] QcomWDogDxe.efi HW Wdog Setting from PCD : Disabled - 0x058A63000 [ 3025] DALTLMM.efi - 0x058A59000 [ 3026] SPMI.efi - 0x058A4F000 [ 3027] ResetRuntimeDxe.efi - 0x058A0E000 [ 3028] PmicDxe.efi PM0: 45, PM1: 37, - 0x0589F4000 [ 3034] PILDxe.efi pil-abl Done t=114ms s=9ms a=56ms f=49ms - 0x058A2E000 [ 3155] WatchdogTimer.efi - 0x0589DF000 [ 3155] ASN1X509Dxe.efi - 0x0589D5000 [ 3156] SecRSADxe.efi - 0x0589B6000 [ 3156] VerifiedBootDxe.efi - 0x0589CD000 [ 3157] EmbeddedMonotonicCounter.efi - 0x0589AD000 [ 3159] RealTimeClock.efi - 0x0589C5000 [ 3160] PrintDxe.efi - 0x058986000 [ 3160] DevicePathDxe.efi - 0x0589A5000 [ 3161] CapsuleRuntimeDxe.efi - 0x13FDA5000 [ 3162] HiiDatabase.efi - 0x0589EA000 [ 3162] FontDxe.efi - 0x13FCF0000 [ 3170] QcomBds.efi - 0x13FD63000 [ 3172] GpiDxe.efi - 0x058904000 [ 3269] I2C.efi - 0x13FD9B000 [ 3270] AdcDxe.efi - 0x13FD92000 [ 3271] UsbPwrCtrlDxe.efi - 0x13FCD4000 [ 3271] QcomChargerDxeLA.efi 3, ChargerLib:: ChargerLibTarget_HWInit PlatformType = 34 has Static PlatHWConfig = 1 3, ChargerLib:: ChargerLibTarget_HWInit PlatformType = 34: ChargerHW = 1, GaugeHW = 1 3, PmicDxe:: PmicFileLog_InitFileLog File Logging is Disabled 3, ChargerLib:: ChargerLibTarget_GetBatteryID BATT_ID_2 = 15245 3, ChargerLib:: ChargerLibTarget_GetBatteryType Battery type = 0 3, ChargerLib:: ChargerLib_SetDAMICL Setting DAM ICL to = 1 3, QcomChargerDxe:: ChargerPlatform_Init Successfully initialized ChargerLibCommon Success 3, PmicDxe:: EFI_PmicSchgEnableChgWdog Charger Watchdog Disabled 3, PmicDxe:: EFI_PmicSchgEnableChgWdog Charger Watchdog Enabled 3, QcomChargerDxe:: ChargerPlatform_Init Enabled WDOG. - 0x13FD89000 [ 3280] ChargerExDxe.efi - 0x13FCB9000 [ 3280] UsbfnDwc3Dxe.efi - 0x13FCAA000 [ 3281] UsbConfigDxe.efi UsbConfigPortsQueryConnectionChange: UFP and Type-C UsbConfigPortsQueryConnectionChange: usbport->connectstate: ATT ConnectSts : Attach, Data Role : UFP (DEVICE Mode), Lane : CC2, CoreNum : 0 HandlePortPartnerXtach: Cable Attach - 0x13FD3F000 [ 3281] ButtonsDxe.efi - 0x05895D000 [ 3283] TsensDxe.efi - 0x13FC2F000 [ 3283] DisplayDxe.efi - 0x13FC9C000 [ 3284] HashDxe.efi - 0x13FC8F000 [ 3285] CipherDxe.efi - 0x13FD37000 [ 3285] RngDxe.efi - 0x13FD2D000 [ 3286] DDRInfoDxe.efi - 0x13FC87000 [ 3286] SimpleTextInOutSerial.efi - 0x13FC7D000 [ 3287] ConPlatformDxe.efi - 0x13FC21000 [ 3288] ConSplitterDxe.efi - 0x13FC15000 [ 3289] GraphicsConsoleDxe.efi - 0x13FC08000 [ 3290] SecurityStubDxe.efi - 0x13FBFB000 [ 3291] UsbMsdDxe.efi - 0x13FBEE000 [ 3291] UsbDeviceDxe.efi - 0x13FBE5000 [ 3292] XResetReasonDxe.efi invalid last_log info smem_get_addr: SMEM get addr success. smem_type=403, buf_size=16 and offset = 0x000071C0. - 0x13FBD9000 [ 3293] TaDxe.efi - 0x13FC6C000 [ 3293] XOemCertDxe.efi - 0x13FBC4000 [ 3294] XBootPALDxe.efi - 0x13FBAB000 [ 3295] UdonDxe.efi - 0x13FBD1000 [ 3295] XGAdcDxe.efi - 0x13FB8A000 [ 3296] XGraphicImagesDxe.efi - 0x13FBA3000 [ 3310] ResetCfgDxe.efi ------ABL FV already mounted BDS Entry [ 3311] Disp init wait [ 3311] rtc raw 101686287 ----------------------------- Platform Init [ 3336] BDS Boot Cycle : 331 Run Cycle : 331 UEFI Ver : 5.0.200304.BOOT.XF.4.0-00203-NICOBARLAZ-1 Platform : IDP Chip Name : SM_NICOBAR Chip Ver : 1.0 Chip Serial Number : 0xB0D025CC ----------------------------- - 0x13FA5C000 [ 3355] QcomChargerApp.efi 3, ChargerLib:: ChargerLibTarget_IsChargingSupported PlatformType = 34: ChargerHW = 1, GaugeHW = 1 3, ChargerLib:: ChargerLibTarget_IsChargingSupported Support Charging = 1 3, ChargerLib:: ChargerLib_IsChargingSupported Support Charging = 1 3, PmicDxe:: EFI_PmicSchgIsBatteryPresent Battery Missing: 0, Battery Missing Latched: 0 (0: present, 1: missing) 3, ChargerLib:: ChargerLibTarget_GetBatteryID BATT_ID_2 = 15258 3, ChargerLib:: ChargerLib_GetBatteryID BATT_ID_2 = 15258 3, ChargerLib:: ChargerLib_GetBatteryType Battery type = 0 3, PmicDxe:: PmicQg_ReadBattTemp: BATT_Temp = 29 3, ChargerLib::ChargerLib_GetBatteryTempStatus BatteryTemp = 29 C 3, PmicDxe:: PmicQg_ReadBattTemp: BATT_Temp = 29 3, ChargerLib:: ChargerLib_GetBatteryVoltageStatus Battery voltage = 4210 mV 3, ChargerLib:: ChargerLib_GetErrors pChargingError = 0 3, QcomChargerDxe:: ChargerPlatform_GetChargingAction Battery Profile Loading Not Required 3, PmicDxe:: PmicQg_ReadBattTemp: BATT_Temp = 29 3, QcomChargerDxe:: ChargerPlatform_CheckIfOkToBoot Good To Boot To HLOS BatteryVoltage= 4210 gThresholdVbatt = 3200 3, QcomChargerDxe:: ChargerPlatform_GetChargingAction Action Returned = 3 3, ChargerLib:: ChargerLib_Exit ChargerLibExit ChargerLib:: no Turn Off LED 3, PmicDxe:: EFI_PmicSchgEnableChgWdog Charger Watchdog Disabled 3, PmicDxe:: EFI_PmicQgExit 3, ChargerLib:: ChargerLibTarget_LedOn LED TURNED OFF = Success 3, PmicDxe:: EFI_PmicSchgEnableChgWdog Charger Watchdog Disabled UEFI Total : 1117 ms POST Time [ 3364] OS Loader - 0x13F851000 [ 3369] LinuxLoader.efi Loader Build Info: Mar 4 2020 14:58:27 VB: RWDeviceState: Succeed using rpmb! Boot counter is 345 XBoot Init Init XBootPALAPILib Init TA API Lib XBOOT (1320-2835_X_Boot_SM6125_LA2.0_Q_31) [ERROR @ xboot_glue.c:83]: Device Key MiscTA unit size is zero [ERROR @ xboot_glue.c:475]: get_dk returned err=-1013 Reading 325 bytes from RPMB, OK Reading 325 bytes from RPMB, OK XBoot MakeDecisions Check authenticated commands [ERROR @ ta_interface.c:325]: Unable to delete TA unit 2334 Make Decisions PBA ID: V5013694A (1) Vendor(0x00000001)->Sony(0x77665501) 3, PmicDxe:: EFI_PmicSchgGetChargerPortType APSD done status: 1 Failed to get pPmicSchgProtocol->DcinValid: Device Error 3, PmicDxe:: EFI_PmicSchgGetChargerPortType APSD done status: 1 Setting existing handle Startup flags: [USB INSERTED] [HARD RESET] Warmboot reason: [NORMAL] [ERROR @ sony_boot_config_parser.c:740]: None or incorrect vbus_pulse configuration! 3, PmicDxe:: EFI_PmicSchgGetChargerPortType APSD done status: 1 Failed to get pPmicSchgProtocol->DcinValid: Device Error 3, PmicDxe:: EFI_PmicSchgGetChargerPortType APSD done status: 1 Reset keys pressed but released before shutdown timer expired. Booting normally. Service mode detected: [NONE] Collect command line additions Obtain backlight config Failed to configure PWM. Status=Device Error Verify OEM unlock flag Request Generate authenticated channel nonce Booting Into Mission Mode Enable XHwreset S2 reset is enabled Setting existing handle GetVmData: No Vm data present! Status = (0x3) VM Hyp calls not present 3, PmicDxe:: EFI_PmicSchgIsBatteryPresent Battery Missing: 0, Battery Missing Latched: 0 (0: present, 1: missing) ChargerExProtocol:: EFI_ChargerExIsOffModeCharging HARD_RESET = 1 .KPDPWR = 0 PON1 = 0 USB_CHG = 0 CBLPWR = 0 ChargerExProtocol:: EFI_ChargerExIsOffModeCharging IsColdBoot = 1 BatteryPresent = 1 ChargerPresent = 1 ChargerExProtocol:: EFI_ChargerExIsOffModeCharging Off mode charging False Active Slot _a is bootable, retry count 6 Booting from slot (_a) LoadImageAndAuth: 1590: CurrentSlot.Suffix=_a Load Image vbmeta_a total time: 1 ms Load Image vbmeta_system_a total time: 2 ms Load Image boot_a total time: 230 ms Load Image dtbo_a total time: 81 ms VB2: Authenticate complete! boot state is: orange VB2: boot state: orange(1) DisplayDxe: Panel ID:0x0000CAFE [LCD] DisplayDxe: Resolution 1080x2520 (1 intf) smem_get_addr: SMEM get addr success. smem_type=402, buf_size=2328 and offset = 0x00007848.IDCF image path = fv1:\verifiedboot_state_orange_1080_2520.bmp.gz Reading 325 bytes from RPMB, OK VB: RWDeviceState: Succeed using rpmb! Device key is not set, setting to zero HwconfRevData is empty, not setting data Reading 325 bytes from RPMB, OK GetVmData: No Vm data present! Status = (0x3) Memory Base Address: 0x40000000 Decompressing kernel image total time: 436 ms IDCF image path = fv1:\logo_sony_1080_2520.bmp.gz Memory Base Address: 0x40000000 Apply Overlay total time: 289 ms @@@ UpdateCmdLine mode = 0 10, PmicDxe:: EFI_PmicSchgIsBatteryPresent Battery Missing: 0, Battery Missing Latched: 0 (0: present, 1: missing) ChargerExProtocol:: EFI_ChargerExIsOffModeCharging HARD_RESET = 1 .KPDPWR = 0 PON1 = 0 USB_CHG = 0 CBLPWR = 0 ChargerExProtocol:: EFI_ChargerExIsOffModeCharging IsColdBoot = 1 BatteryPresent = 1 ChargerPresent = 1 ChargerExProtocol:: EFI_ChargerExIsOffModeCharging Off mode charging False Cmdline: androidboot.hardware=qcom androidboot.memcg=1 lpm_levels.sleep_disabled=1 video=vfb:640x400,bpp=32,memsize=3072000 msm_rtb.filter=0x237 service_locator.enable=1 swiotlb=1 loop.max_part=7 cgroup.memory=nokmem,nosocket buildproduct=pdx201 buildid=S cmdline: "androidboot.hardware=qcom androidboot.memcg=1 lpm_levels.sle"\ "ep_disabled=1 video=vfb:640x400,bpp=32,memsize=3072000 msm_r"\ "tb.filter=0x237 service_locator.enable=1 swiotlb=1 loop.max_"\ "part=7 cgroup.memory=nokmem,nosocket buildproduct=pdx201 bui"\ "ldid=SEINE-1.0.0-200331-1752 buildvariant=user androidboot.v"\ "erifiedbootstate=orange androidboot.keymaster=1 androidboot."\ "vbmeta.device=PARTUUID=87ea1d55-4627-4a22-bfe0-7860349b4659 "\ "androidboot.vbmeta.avb_version=1.0 androidboot.vbmeta.device"\ "_state=unlocked androidboot.vbmeta.hash_alg=sha256 androidbo"\ "ot.vbmeta.size=7488 androidboot.vbmeta.digest=4d5e84bbb596e0"\ "07bc9207f2353803c9deb858dca0a17cecb62f7c706a2ae54e androidbo"\ "ot.vbmeta.invalidate_on_error=yes androidboot.veritymode=enf"\ "orcing androidboot.bootdevice=4744000.sdhci androidboot.boot"\ "_devices=soc/4744000.sdhci androidboot.baseband=msm msm_drm."\ "dsi_display0=6: androidboot.slot_suffix=_a rootwait ro init="\ "/init androidboot.dtbo_idx=0 androidboot.dtb_idx=7 androidb"\ "oot.bootloader=xboot oemandroidboot.xboot=1320-2835_X_Boot_S"\ "M6125_LA2.0_Q_31 androidboot.serialno=QV724FJP3A startup=0x0"\ "0008004 warmboot=0x77665501 oemandroidboot.babe09a9=00 oeman"\ "droidboot.babe137e=6a oemandroidboot.imei= oem"\ "androidboot.securityflags=0x00000003". RAM Partitions Add Base: 0x0000000040000000 Available Length: 0x000000003DD00000 Add Base: 0x0000000080000000 Available Length: 0x00000000C0000000 smem_get_addr: SMEM get addr success. smem_type=402, buf_size=2328 and offset = 0x00007848.smem_get_addr: SMEM get addr success. smem_type=603, buf_size=104 and offset = 0x00008170.ERROR: Could not get splash memory region node Update Device Tree total time: 105 ms Shutting Down UEFI Boot Services: 10544 ms EFI_UdonStop Stop DebugPort for anti-corroding \0 ```

How to reproduce It is reproducible for me with all SW versions offered by Emma for this device at the moment (and Emma is the flashing method I used for these):

I have also built my own userdebug image of Android, but also see no logs on the UART, same symptoms as any other image.

This device was previously flashed with some version on Sailfish OS, but I expect everything relevant to be reflashed back to stock versions by Emma.

bartcubbins commented 3 months ago

you need to uncomment this https://github.com/sonyxperiadev/device-sony-common/blob/master/CommonConfig.mk#L36 and this (if you need earlycon) https://github.com/sonyxperiadev/device-sony-seine/blob/master/PlatformConfig.mk#L32 and rebuild the kernel with this flag CONFIG_SERIAL_MSM_GENI_CONSOLE

parport0 commented 3 months ago

Thank you.

Adding console=ttyMSM0,115200,n8 androidboot.console=ttyMSM0 and earlycon=msm_geni_serial,0x4a90000 to the kernel cmdline and CONFIG_SERIAL_MSM_GENI_CONSOLE=y to the kernel config works.

I was worried this was related to this "anti-corroding" (😄) message, happy to be wrong.