EG915N-EU firmware boot messages on reset

Sometimes, but not always, when I perform soft-reset with AT+CFUN=1,1 I get a lot of boot messages on the main serial port (see below).

This is not expected of course and, while it could nice for debugging, in regular cases it might cause issues.

We are using the module on a custom design, I suspect some reserved pin might trigger this behavior. Can you suggest something to check? Or is this a firmware issue (version in the log below)?

OK
36ba PowerControl Entrance
36ba to reset
373d net ready...
373d powerctl start
373f flash ready...

OK
3938 powerctl ready...
3938 ready to reset
Û;ÛÛ“K  [INFO: CPU       ] CHIP_ID: 0x1603, REV_ID: 0xA7
[INFO: CPU       ] PLATFORM: CRANEM (SILICON)
[INFO: Main      ]
[INFO: Main      ] Starting AROM-CRANE (Version: 2020.07.30)
[INFO: Qspi      ] QSPI clock configured at 13 MHz
[INFO: QspiFlash ] Detecting QSPI flash devices...
[INFO: QspiFlash ] Found a known spi flash device "GD25LQ128D"
[INFO: QspiFlash ] SPI nor flash: Manufacturer ID: 0xC8, Device ID: 0x6018
[INFO: UbiSimple ] Detected peb size is 4096, the first good peb number is 0
[INFO: Crypto    ] Initializing crypto library...
[INFO: Main      ] Running in normal booting mode.
[INFO: Main      ] Loading...
[INFO: Bl1Main   ] Welcome to boot rom.
[INFO: Bl1Main   ] ### Non-trusted boot mode. ###
[INFO: Bl1Main   ] Found preboot volume, size is 43932 bytes
[INFO: Bl1Main   ] BL1: Trying to load and verify BL2 image from volume preboot...
[INFO: Bl1Main   ] BL1: OKay.
[PRI : Preboot   ] Executing preboot application...
[PRI : Preboot   ] Preboot version: 2024.04.12
[PRI : Preboot   ] Usb phy reg 29 0x0 -> 0x0
[PRI : Preboot   ] hot power on

PMIC REG:0x00,0x01,0x10,0x13,0x14,0x18,0xE2,0xE5,0xE6,0xF0
PMIC VAL:0x13,0x60,0x20,0x00,0x00,0x08,0xF1,0x04,0x00,0x20
[PRI : PMIC      ] Found PMIC with Id: 0x13
[PRI : PMIC      ] PMIC watchdog is disabled, reg val = 0x1
[PRI : Psram     ] [PSRAM] psram init Crane common.
[PRI : EFuse     ] No embedded flash
[PRI : Psram     ] WB_250MHZ_8M8M
[PRI : Psram     ] [PSRAM] psram init set WBD drive_strength = WBD_DRIVE_115ohm .
[PRI : Psram     ] Psram cache enabled !!! :cache size=[128B], @[0xC0104000]=[0x000A3B11]
[INFO: Bl1Main   ] Found bootloader volume, size is 71268 bytes
[INFO: Bl1Main   ] BL1: Trying to load and verify BL2 image from volume bootloader...
[INFO: Bl1Main   ] BL1: OKay.
[PRI : Boot2     ] Executing boot2 application...
[PRI : Boot2     ] Boot2 version: 2024.04.12
[ERR : SecureBoot] Flash init fail!
[WARN: Boot2     ] usb is not connected
[ERR : SecureBoot] Flash init fail!
quec_cfg fail 2124283905
Boot33 UART INIT DONE
[BOOT33]VB_VERSION_DATE   :[20210625]
[BOOT33]VB_OEM_LCD_TYPE   :[NO_LCD]
[BOOT33]VB_SECBOOT_SUPPORT:[NON-SECBOOT]
[BOOT33]build_info_string :[boot33.bin 20210329_db]
ASR_PROP_AREA_MAGIC detect
PowerOnLog: 0x20
Built by DS-5.
boot33 MPU config
READ_ID=22
dummy_cycles already set to 6
READ_ID=22
dummy_cycles already set to 6
Qspi clk=104, QSPI_CLK_RES_CTRL = 0x1db, mfr_id=0xc8,dev_id:0x6018
>>>Instruction mode (Wait for CTRL+C):
>
crane_set_fbp:protect_start_addr[0x0],protect_end_addr[0x7a4000]
qspi_nor_find_fbp: flash size is 0x1000000, name is GD25LQ128D
qspi_nor_find_fbp:find type is 11, protect area=0x0~0x3fffff
qspi_nor_set_fbp:org status1[0x0],status2[0x2].
qspi_nor_set_fbp:new status1[0x34],status2[0x2].
qspi_nor_set_fbp:read back,n_status1[0x34],n_status2[0x2].
qspi_nor_set_fbp:fbp valid.
[OTA] get updater version 20220923_ver2 !
[OTA] get updater solution FOTA_ASRDM !
[OTA] NO FOTA FLAG DETECTED
[Quec][Flash]:Abnormal Erasedblock not found(i=509)
[Quec][Flash]:Abnormal Erasedblock not found(i=509)
[---------------------------------------------------------]
[LOADTABLE AREA ][LOADTABLE_AREA_HEADER                   ]
[INIT_ROUTINE   ][7e7b00e8                                ]
[---------------------------------------------------------]
[LOADTABLE AREA ][LOADTABLE_AREA_VER_INFO                 ]
[ANTI_RB_VER    ][20190904                                ]
[EXECUTE_MODE   ][XIP                                     ]
[PS_MODE        ][LTEGSM                                  ]
[IMAGE_DESC     ][CRANE_DS_TX_Z2A0_LTEGSM_DKB_XIP_LWIP_MODULE_CIRAM_CSD_GENERIC_SDRW_CPZ_1DDR_RW_]
[---------------------------------------------------------]
[LOADTABLE AREA ][LOADTABLE_AREA_RW_CPZ_INFO              ]
[RW_CPZ_1][DDR_RW_][7e9e0200][80144400][00008000][80145000]
[RW_CPZ_2][PS_NCAH][7ef54000][80170a5c][00001000][8014d000]
[RW_CPZ_3][USBNCAH][7efc3800][80171d5c][00001000][8014e000]
[RW_CPZ_4][CODE_PS][7e210000][80172070][00106000][8014f000]
[RW_CPZ_5][CODEPSB][7e40c100][8036ce30][00110000][80255000]
[RW_CPZ_6][CODE_PL][7e5f6a00][80555588][000ff000][80365000]
[RW_CPZ_7][NON_OTA][7e809d00][80762eac][000e6000][80464000]
[---------------------------------------------------------]
[LOADTABLE AREA ][LOADTABLE_AREA_ARMLINK_SYMBOL           ]
[00.CP_EXEC     ][0x80040000][AVAILABLE                   ]
[01.CP_LOAD     ][0x4c4c554e][INVALID                     ]
[02.IMG_END     ][0x4c4c554e][INVALID                     ]
[03.BIN_SIZE    ][0x0050a000][AVAILABLE                   ]
[04.DSP_BEGIN   ][0x7e000000][AVAILABLE                   ]
[05.DSP_END     ][0x7e20fffc][AVAILABLE                   ]
[06.RF_ADDR_Z2  ][0x7e090000][AVAILABLE                   ]
[07.RF_ADDR_A0  ][0x7e090000][AVAILABLE                   ]
[08.RD_BEGIN    ][0x80028000][AVAILABLE                   ]
[09.RD_END      ][0x80038000][AVAILABLE                   ]
[10.APN_BEGIN   ][0x80038000][AVAILABLE                   ]
[11.APN_END     ][0x80040000][AVAILABLE                   ]
[12.FOTA_PRM_S  ][0x4c4c554e][INVALID                     ]
[13.FOTA_PRM_E  ][0x4c4c554e][INVALID                     ]
[14.UPDATER_S   ][0x4c4c554e][INVALID                     ]
[15.UPDATER_E   ][0x4c4c554e][INVALID                     ]
[16.FOTA_PKG_S  ][0x4c4c554e][INVALID                     ]
[17.FOTA_PKG_E  ][0x4c4c554e][INVALID                     ]
[18.NVM_BEGIN   ][0x4c4c554e][INVALID                     ]
[19.NVM_END     ][0x4c4c554e][INVALID                     ]
[20.F_A_START   ][0x80fe0000][AVAILABLE                   ]
[21.F_A_END     ][0x80ff0000][AVAILABLE                   ]
[22.F_B_START   ][0x80ff0000][AVAILABLE                   ]
[23.F_B_END     ][0x81000000][AVAILABLE                   ]
[24.DDR_RO_ADD  ][0x80042000][AVAILABLE                   ]
[25.DDR_RO_LEN  ][0x000f2b9c][AVAILABLE                   ]
[26.HEAP_GU_BG  ][0x7ec16d00][AVAILABLE                   ]
[27.HEAP_GU_ED  ][0x7ee73ffc][AVAILABLE                   ]
[28.DSPBK_SIZE  ][0x00100000][AVAILABLE                   ]
[---------------------------------------------------------]
[LOADTABLE AREA ][LOADTABLE_AREA_FUNC_VAL                 ]
[00.VERGIN      ][ffffffff                                ]
[01.BOOTCOUNT   ][ffffffff                                ]
[02.UART_PRT    ][1                                       ]
[03.FATAL_PRT   ][1                                       ]
[04.DEF_FREQ    ][ffffffff                                ]
[05.CORE_VOL    ][ffffffff                                ]
[---------------------------------------------------------]
malloc init done!
load logo in ptable
logo flash start addr:0x80663000
LogoHeaderInfo size:0x1a0
logo compressed magic: 0x8000005d
logo magic:0xbabe5f5f, entry point: 0x7e0402a4,load addr: 0x7e040000, header file size:0x1a0
lzma cpmpressed image
enable_cache startup_time_flag = 0x0
start lzma decompress logo
[LOGO] load header info from flash to psram
decompress logo from flash to psram
src_addr:[0x806631a0],src_len:[0x00005e60],dst_addr:[0x7e0401a0], logo in flash type:1
inLen=[0x00005c28], outLen=[0x0000b87c]
disable_cache startup_time_flag = 0x0
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 B33 JUMP TO LOGO at 0x7e0402a4
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
LOGO START
LCD_TYPE:[NO_LCD]
ver:20210419_db
LOGO_FLAG:[00]
ASR_PROP_AREA_MAGIC detect
READ_ID=22
dummy_cycles already set to 6
READ_ID=22
dummy_cycles already set to 6
Qspi clk=104, QSPI_CLK_RES_CTRL = 0x1db, mfr_id=0xc8,dev_id:0x6018
logo LOGO_IMG_END_ADDR[7e0e0000]!
enable_cache startup_time_flag = 0x0
load logo in ptable
logo flash start addr:0x80663000
LogoHeaderInfo size:0x1a0
Decompress dsp and rw data start!
chip id: 0x00a71603
LZMA compressed DSP image.
[LzmaUncompress] src: [0x8054a000], srclen: [0x00110d2f],dst: [0x7e210000], dstlen: [0xffffffff][DSP] released dsp outLen [0x00210000] inLen[0x00110d22]
[DSP] backup dsp size[00100000] to address[0x7ec16d00]
[DSP] copy dsp to address[0x7e100000] len[0x00110000]
[CP ] CHIP_ID=[00a71603] USING DEFAULT VALUE
[RF] nornal,size=32768
[RF ] copy from [0x8065b000] to [0x7e090000] size[0x00008000]
not a compressed image
[RF ]copy rf SUCCEED
Region CPZ struct detected from LDT
disable_cache startup_time_flag = 0x0
Decompress dsp and load rf data END!
LOGO END

 ********************************************
 ** BOOTLOADER DONE JUMP TO CP IMAGE
 ** VERSION : 20210625
 ** PC      : 0x80040000
 ********************************************
0

0 silentreset, don't need to dump

0 Qspi clk=104, QSPI_CLK_RES_CTRL = 0x1db, mfr_id=0xc8,dev_id:0x6018


0 qspi_nor_find_fbp:find type is 12, protect area=0x0~0x7fffff

2 qspi_nor_set_fbp:org status1[0x0],status2[0x2].

2 qspi_nor_set_fbp:new status1[0x38],status2[0x2].

3 qspi_nor_set_fbp:read back,n_status1[0x38],n_status2[0x2].

540 XML VERSION:QCFG=16,IMS=16

544 XML USER INFO:QCFG=0,IMS=0

5aa XML CRC:QCFG=0xF891C5F4,FILE=0xF891C5F4,IMS=0xF891C5F4

661 XML DON'T NEED OPERATE
152e u27 mrd_extra_info_init,adc_type=0,a_ok=1,b_ok=1


28 mrd_extra_info_init,adc_type=1,a_ok=1,b_ok=1


2b factory is not change,not record again


1c6b quec usb nema cfg nv init: value 0 read failed
2d [Egan]usb_device_init,usb_mode=69


1df1 USB2DeviceEndpointOpen: ep#=7 type=6 buff=0x0
,r14=7E6FA029
1e5d USB2DeviceEndpointOpen: ep#=3 type=6 buff=0x0
,r14=7E6FA04F
1f23 USB2DeviceEndpointOpen: ep#=12 type=4 buff=0x0
,r14=7E6FA075
1ff2 USB2DeviceEndpointOpen: ep#=8 type=6 buff=0x0
,r14=7E6FBE0F
20b2 USB2DeviceEndpointOpen: ep#=1 type=6 buff=0x0
,r14=7E6FBE39
2178 USB2DeviceEndpointOpen: ep#=10 type=4 buff=0x0
,r14=7E6FBE65
2241 USB2DeviceEndpointOpen: ep#=6 type=6 buff=0x0
,r14=7E6FBEB3
2307 USB2DeviceEndpointOpen: ep#=15 type=4 buff=0x0
,r14=7E6FBEDB
23d0 USB2DeviceEndpointOpen: ep#=9 type=6 buff=0x0
,r14=7E6FBF1F
2497 USB2DeviceEndpointOpen: ep#=14 type=6 buff=0x0
,r14=7E6FBF55
2573 USB2DeviceEndpointOpen: ep#=2 type=6 buff=0x0
,r14=7E727FAB
2626 USB2DeviceEndpointOpen: ep#=11 type=4 buff=0x0
,r14=7E727FD1
31 Egan audio usb storage:0, desc:69

32 Usb mode 0, descriptor 69


34 ACMSetAudioConfigPara: audio_PCM_Print:1, ACMCOMM_CombinedSPK=0, audio_IsBypassPM813PA=0

35 ACMSetAudioConfigPara: audio_disableHSDetect=1, audio_pm802_use_codec=0, audio_hs_normal_closed=0

40 ACMSetAudioConfigPara: audio_PCM_Print:1, ACMCOMM_CombinedSPK=0, audio_IsBypassPM813PA=0

41 ACMSetAudioConfigPara: audio_disableHSDetect=1, audio_pm802_use_codec=0, audio_hs_normal_closed=0

43 power_up_reason: 0x20, power_down_reason: 0x0

3339 read g_quec_nat_flag=0 fail
333d mifi mode
45 lwip: lwip_init_all done!

46 ######## quec_system_init ok ########
47 EG915NEUAPR03A05M16 V02
47  Application Start...
48  ATCmdSvrRdy
3a7a cpqd will use default val
3ac2 ceercatcfg will use default val
3f21 usb get ifc value fail rts_control=0,cts_control=0
3fad read remoteip=0,ret=5
3fbb remoteip read fail
40f3 cts value=0 not need init
41d5 debounce timer read fail,use default value
42d8 usim wakeup flag read fail,use default value=0
88 InitIPCControl: data:0x0

9f quec_modem_channel_init: done

9f modem_msgq_init: done

a0 modem_if_init: done
a0 modem_router_create: done
a1 modem_init_internal: done
a1 AT command server ready!

a2 Booting done

cf CLAT USE DEFAULT
906c dsss sim2 read_cfg=1,dftcid=1
db quec_transmission_rate_config!!!
db audio_init!!!
db quec_audio_gain_table_config!!!
e1 mode = 0 mode = 0

e2 quec_rt5616_read_reg!!!
9b9c msg process queue already create
e7 quec_init failed!

RDY
ea SW restart reason: Normal power on

hi ,

Could you please tell me if the logs you provided were read from the serial port? Where did this log print come from?

Yes, this comes from the main serial port of the EG915N module, pin MAIN_TXD, after I issue the command AT+CFUN=1,1

@Duncan.Xu-Q Could you please check if this is a normal print?

I shall add that I get messages printed on the Main UART also at power down:

AT+QPOWD<CR>

1921 PowerControl Entrance

OK
1a9d net ready...
1a9d powerctl start
1a9f flash ready...

POWERED DOWN
1c97 powerctl ready...
1c97 shut down
1c97 +PMIC_SW_POWERDOWN,pmic_id=0x2

I suspect some reserved/floating pin is activating this function, or maybe it is a firmware issue.
I have a custom board sample where this happens all the times on software reset and power down, and another board sample where it happens sometimes.

Hello, any chance you had a look at this issue?