sonyxperiadev/bug_tracker

No UART logs from Android -- only from the bootloaders

parport0 opened this issue · 2 comments

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=<REDACTED> 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):

  • XQ-AU52 59.0.A.1.296 Customized_UK 1321-9381 R4A User-Live COM
  • XQ-AU52 59.0.A.6.24 Customized_UK 1321-9381 R6A User-Live COM
  • XQ-AU52 59.1.A.2.169 Customized_UK 1321-9381 R4B User-Live COM

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.

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

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.