Can't boot from POWER OFF state with SD-CARD in slot

VIM4
1

Which system do you use? Android, Ubuntu, OOWOW or others?

Ubuntu

Which version of system do you use? Khadas official images, self built images, or others?

vim4-ubuntu-22.04-server-linux-5.4-fenix-1.2-221018-emmc.img.xz
The latest ubuntu server from 18-Oct-2022

Please describe your issue below:

The VIM4 does not boot and hangs when starting from a POWER OFF state when an SD-Card is inserted. The SanDisk Ultra 256 GB card was partitioned with fdisk as a dos device with four partitions which are formatted as ext4. ie… mmcblk1p1…mmcblk1p4

The VIM4 starts up fine with the same card inserted when rebooted. I can do this by powering up the VIM4 without the sd-card inserted and then inserting it once booted. I can then reboot the system with the command prompt.

The VIM4 also hangs when restarted with the RESET button.

Post a console log of your issue below:

I’ll post the appropriate log once someone tells me which one I should look in.
I know that the kern.log never gets updated when the system hangs and the dmesg log ends before the wi-fi radios timeout (IIRC).

Is the VIM4 trying the boot from the sd-card? Why would it do that when there is no OS on it?

Thanks for you help.

2

I might be wrong here, but basing off of my own setup i have an image on my micro sd card which is always inserted, but my VIM4 always boots from the emmc, i think there is a setting in the OOWOW firmware where you can change the boot order as by default i have read in a previous thread that it always prioritises the sd card on boot from stock

3

It is currently setup to boot form the sd-card first and I prefer it that way so I can boot with an OOWOW image and upgrade the SPI version easily.

I’ve had my VIM4 for over a month now and the ‘problem’ above just recently started. Come to think of it… I’ve only experienced this behaviour with the latest ubuntu server image. Hmmm. I have a backup dump which is based on the previous ubuntu server image which has no trouble booting with the sd-card inserted (although at that time it only had one partition).

The first time I noticed this I thought I screwed up the server somehow and started from scratch again. Then it happened again which prompted me to do more troubleshooting.

4

I have an update…
I started with a fresh install of the latest ubuntu server from Oct 2022. In this state the VIM4 was able to boot into the Ubuntu from eMMC with the sd-card inserted from a power off state.
I then did an update, full-upgrade, and a sync. I powered off the VIM4 with the poweroff command.
The VIM4 now hangs during start up while the sd-card is inserted.

SO… it appears that something in the update/upgrade broke the boot process.

Here’s the last part of the /var/log/apt/history.log (line breaks added for readability)

Start-Date: 2022-10-23 01:30:00
Commandline: apt full-upgrade
Requested-By: khadas (1000)

Install:
systemd-hwe-hwdb:arm64 (249.11.1, automatic)

Upgrade:
libperl5.34:arm64 (5.34.0-3ubuntu1, 5.34.0-3ubuntu1.1),
libpulse0:arm64 (1:15.99.1+dfsg1-1ubuntu1, 1:15.99.1+dfsg1-1ubuntu2),
udev:arm64 (249.11-0ubuntu3, 249.11-0ubuntu3.6),
git:arm64 (1:2.34.1-1ubuntu1.4, 1:2.34.1-1ubuntu1.5),
perl:arm64 (5.34.0-3ubuntu1, 5.34.0-3ubuntu1.1),
libudev1:arm64 (249.11-0ubuntu3, 249.11-0ubuntu3.6),
perl-base:arm64 (5.34.0-3ubuntu1, 5.34.0-3ubuntu1.1),
sudo:arm64 (1.9.9-1ubuntu2, 1.9.9-1ubuntu2.1),
libksba8:arm64 (1.6.0-2build1, 1.6.0-2ubuntu0.1),
perl-modules-5.34:arm64 (5.34.0-3ubuntu1, 5.34.0-3ubuntu1.1),
git-man:arm64 (1:2.34.1-1ubuntu1.4, 1:2.34.1-1ubuntu1.5),
linux-libc-dev:arm64 (5.15.0-50.56, 5.15.0-52.58)

End-Date: 2022-10-23 01:30:18

Which of the above is the troublemaker?

5

Further update:
I installed the previous ubuntu server image from July and did an update and upgrade. The VIM4 starts up fine from a poweroff state even with the sd-card inserted.

So… is there any disadvantages of using the July image over the October image?

6

Hello @pixelgazer

So it bootup well with the original latest image 1.2-221018 with SD card inserted, right? But can’t bootup with a upgrade?

Have you checked with other SD cards do they have the same issue?

Could you be able to provide the full boot log with serial debug console?

https://docs.khadas.com/products/sbc/vim4/development/setup-serial-tool

7

Hi @numbqq, Thanks for the reply.

Correct. It also boots correctly (with sd-card inserted) on a fully upgraded system based on the previous 1.1-220721 image. I’ve gone back to using that image as my starting point for building up my server.

I have not tried a different sd-card but I will when I have a chance.

I can’t provide a full boot log atm as my Serial TTL-to-USB adapters are packed away. But I will attempt to capture it via an old/original raspberry pi. This may take a few days to setup but is probably faster than buying even more serial ttl-to-usb adapters. Reminder to myself… check that the TTL levels on the original pi are the same as the VIM4!

8

@numbqq Hi again, I’m back with a captured boot log and a little tidbit of information.

The log…

øT7:BL:055c20;ID:905660110961151A;FEAT:30F:1FFF0000:B002F:1;POC:CF;RCY:0;OVD:0;DFU:0;SD:0;RD-0:0;CHK:1;eMMC:0;RD-0:0;CHK:0;SCS:0;

Bl2_early_platform_setup: indicates bl2ex flow!
failed to read efuse, set the default voltage:0.83v
0005000dfe05e000

OTP_LIC00 : 0f0300000000ff1f2f000b0000000000
OTP_LIC10 : 008207000001fc000c00001000000300
OTP_LIC20 : ffffffbfffff0700ff80008003000003
OTP_LIC30 : 00000002010000008f03000203000000

TE: 640345

BL2 Built : 15:55:21, Sep 13 2022. t7 origin/master g80f6117 - jenkins@walle02-sh

Board ID = 5
Set sys clock to 24Mhz
syspll is 1512Mhz. Locked
sys1pll is 1608Mhz. Locked
Set sys clock to 167Mhz
gp0pll is 0Mhz. Locked
bl2_platform_setup
boot area list: 
1STBLOB	00000200	00040000
BL2E	00040200	00013000
BL2X	00053200	00011000
DDRFIP	00064200	00040000
DEVFIP	000a4200	00300000
s_setup from rom:00010081
dma mode
derive RSPK OK
DDR driver_vesion: AML_S_PHY_T7_1_18 build time: Sep 13 2022 15:55:10
ddr id: 0

ddr clk to 2016MHz

ch0 clk 2016
ch1 clk 2016PIEI done
Cfg max: 2, cur: 1. Board id: 255. Force loop cfg

LPDDR4 probe

ddr clk to 2016MHz
Check phy result
INFO : End of CA training
INFO : End of initialization
INFO : Training has run successfully!
Check phy result
INFO : End of initialization
INFO : End of read enable training
INFO : End of fine write leveling
INFO : End of read dq deskew training
INFO : End of MPR read delay center optimization
INFO : End of Write leveling coarse delay
INFO : End of write delay center optimization
INFO : End of read delay center optimization
INFO : End of max read latency training
INFO : Training has run successfully!
ch0 1D training succeed
Check phy result
INFO : End of CA training
INFO : End of initialization
INFO : Training has run successfully!
Check phy result
INFO : End of initialization
INFO : End of read enable training
INFO : End of fine write leveling
INFO : End of read dq deskew training
INFO : End of MPR read delay center optimization
INFO : End of Write leveling coarse delay
INFO : End of write delay center optimization
INFO : End of read delay center optimization
INFO : End of max read latency training
INFO : Training has run successfully!
ch1 1D training succeed
Check phy result
INFO : End of initialization
INFO : End of 2D write delay Voltage center optimization
INFO : End of 2D write delay Voltage center optimization
INFO : End of 2D read delay Voltage center optimization
INFO : End of 2D read delay Voltage center optimization
INFO : Training has run successfully!

R0_Rx=9 steps R0_Tx=10 steps Vref_Margin_R0=18 Dramvref_Margin_R0=20
R0_Rx=12 steps R0_Tx=10 steps Vref_Margin_R0=20 Dramvref_Margin_R0=21
soc_vref_reg_value 0x 00000020 00000021 00000021 00000021 00000021 00000020 00000022 00000020 00000021 00000022 00000023 00000021 00000022 00000022 00000021 00000023 00000021 00000021 00000022 00000024 00000021 00000021 00000022 00000020 00000022 00000022 00000021 00000021 00000022 00000022 00000023 00000023
mr8=00000011
dram_verdor_id=00000006
mr18=00000054
mr19=00000004 dram_vref_reg_value 0x 00000008
ch0 2D training succeed
Check phy result
INFO : End of initialization
INFO : End of 2D write delay Voltage center optimization
INFO : End of 2D write delay Voltage center optimization
INFO : End of 2D read delay Voltage center optimization
INFO : End of 2D read delay Voltage center optimization
INFO : Training has run successfully!

R0_Rx=9 steps R0_Tx=10 steps Vref_Margin_R0=19 Dramvref_Margin_R0=19
R0_Rx=11 steps R0_Tx=11 steps Vref_Margin_R0=19 Dramvref_Margin_R0=21
soc_vref_reg_value 0x 00000021 0000001f 00000021 00000021 00000021 00000021 00000022 00000022 00000022 00000023 00000022 00000020 00000021 00000020 00000022 00000022 00000020 0000001f 00000021 0000001f 0000001f 0000001f 0000001f 0000001f 0000001f 0000001f 00000020 0000001f 0000001f 0000001f 00000020 00000020
mr8=00000011
dram_verdor_id=00000006
mr18=0000004c
mr19=00000004 dram_vref_reg_value 0x 00000008
ch1 2D training succeed

100bdlr_step_size ps== 406

100bdlr_step_size ps== 427

finnal_config_axi
finnal_config_axiset_cci_config:
cpu0_gic_init done
start ao cpu:
Wait AO...done.
debug_read..
SYSCTRL_CCI_CFG1==ffff3fff
SYSCTRL_CCI_CFG9==aaaaaaaa
SYSCTRL_NOC_CFG0==00000000
dram_size_config==10001000ap ao cmd ok
DDR cs0 size: 2048MB
DDR cs1 size: 2048MB
DMC_DDR_CTRL: 00e00044DDR size: 3584MB
DDR cs0 size: 2048MB
DDR cs1 size: 2048MB
DMC_DDR_CTRL: 00e00044DDR size: 3584MB
result report

non-sec scramble use random key
scramble use random key
ddr scramble enabled

INFO: bl2_load_bl2ex start!
INFO: load ...
Load: BL2E From: eMMC - 3.0 src: 00002000, dst: 00fffff0, size: 00011000
sdemmc src: ;
INFO: check ...
SHA CHK OK!

aml log : dump from buffer 01000000
56 d9 25 42 e3 66 20 59 34 60 7c ab a7 53 de 08
78 8e 84 3a 8a 98 b7 26 a1 bf 63 5d 79 44 1f 75

INFO: load ...
Load: BL2X From: eMMC - 3.0 src: 00000000, dst: 007ffff0, size: 00011000
sdemmc src: ;
INFO: check ...
SHA CHK OK!

aml log : dump from buffer 00800000
dc 2c fc e6 5b fd 25 3a a5 0c c2 b2 3f 72 cc c8
0b a3 b5 b9 cf 47 49 f5 e3 28 8c a5 84 ac 9d 1d

run into bl2e
info: get valid params from BL2 !
BL2E: do things as vendor specific ... 
Hello world, now in BL2E

TE: 1524038

BL2E Built : 12:23:58, Sep  9 2022. t7 origin/master g0a0ad46 - jenkins@walle02-sh


 Start to do bl2e platform setup !
boot area list: 
1STBLOB	00000200	00040000
BL2E	00040200	00013000
BL2X	00053200	00011000
DDRFIP	00064200	00040000
DEVFIP	000a4200	00300000
eMMC boot @ 0
sw-hs2 s
tun-w: s=0, sz=3
sw8 s
aml log : BL2E load BL3X.....

TE: 1529153
Load FIP HDR from eMMC, src: 0x00000000, des: 0x00300000, size: 0x00008000, part: 0
Load BL3X from eMMC, src: 0x00008000, des: 0x00308000, size: 0x0026c260, part: 0
bl30 payload size: 0x00010260
bl30 memcpy 
bl40 payload size: 0x00018470
bl31 payload size: 0x00040470
bl32 payload size: 0x00080470
bl33 memcpy
bl33 payload size: 0x00180260 offset: 0x000f4000
aml log : BL2E loading BL3X is done...!
boot bl2x
params to bl2x, address=0x0100d190


 Hello, we are in BL2X world !

TE: 1583730

BL2X Built : 19:48:00, Aug 18 2022. t7 origin/master g161cca2 - jenkins@walle02-sh

bl2_platform_setup
INFO: get valid list_blobinfo, 0x0100d190
Info: get valid bl31 payload info, address= 0x00332000 size= 0x00040470
Info: bl31 image is now ready !
Info: get valid bl40 payload info, address= 0x00319000 size= 0x00018470

FEAT_DISABLE_SECURE_ENCLAVE: 1
bl2e_2 entry: 010000c0
run into bl31
NOTICE:  BL31: v1.3(release):04366b46f
NOTICE:  BL31: Built : 18:18:47, Sep 13 2022. t7 remotes/firmware/amlogic-dev-1.3 g04366b46f - jenkins@walle02-sh
BL31:tsensor calibration: tsensor1 = 96000073
BL31:tsensor calibration: tsensor2 = 96000081
BL31:tsensor calibration: tsensor3 = 9600008e
BL31:tsensor calibration: tsensor4 = 960000fe
BL31:tsensor calibration: tsensor5 = 96000054
BL31:tsensor calibration: tsensor6 = 960000b2
[mhu]: mhu_init-v1
[mhu]: 0xfe007100, 0x12120210
[mhu]: 0xfe007104, 0x12121002
[mhu]: 0xfe00710c, 0xa0a0802
[mhu]: 0xfe007118, 0x12120210
[mhu]: 0xfe00711c, 0x12121002
[mhu]: 0xfe007120, 0x10101010
[mhu]: 0xfe007124, 0x10101010
[mhu]: 0xfe007020, 0x3
[mhu]: 0xfe007028, 0x10
[mhu]: 0xfe007024, 0x8
[mhu]: 0xfe00702c, 0x10
[mhu]: 0xfe007040, 0x9089
[mhu]: 0xfe007044, 0x0
[mhu]: 0xfe007048, 0x660
[mhu]: 0xfe00704c, 0x0
[mhu]: 0xfe007050, 0x90006
[mhu]: 0xfe007054, 0x0
[mhu]: 0xfe007058, 0x66000
[mhu]: 0xfe00705c, 0x0
[mhu]: mhu_init-v1 1230 done
DEVICE_MVN=0x0
NOTICE:  BL31: T7 normal boot!
NOTICE:  BL31: BL33 decompress pass
E/TC:0 00 INFO:    BL3-2: ATOS-V3.8.0-7fa9194ef (gcc version 8.3.0 (GNU Toolchain for the A-profile Architecture 8.3-2019.03 (arm-rel-8.36))) #1 Fri Sep  9 03:22:52 UTC 2022 arm
E/TC:0 00 INFO:    BL3-2: secure time TEE
E/TC:0 00 INFO:    BL3-2: Chip: T7 Rev: B (36:B - 0:3)
Hello world again, bl2e meet you guys!
valid entry info for bl33, pc = 0x00000000
======== smc start aocpu ========

Starting AOCPU FreeRTOS...
AOCPU image version='khadas-vims-v2019.01 38e3bfd23466dab11042db1bf1ab83bed6263c00 03:37:11 2022-10-18'
AOCPU_IRQ_SEL=0x0
AOCPU_IRQ_SEL=0x0
AOCPU_IRQ_SEL=0x0
AOCPU_IRQ_SEL=0x0
[AOCPU]: mailbox init start
reg idx=0 cmd=6 handler=f70269d0
reg idx=1 cmd=7 handler=f70269ba
[AOCPU]: mailbox init end
[AOCPU Led]: leds state init!
reg idx=2 cmd=f7 handler=f702181e
[AOCPU Led]: Starting leds task ...
Starting timer ...
reg idx=3 cmd=b4 handler=f70236b8
reg idx=4 cmd=b5 handler=f7023650
reg idx=5 cmd=b6 handler=f70230ce
reg idx=6 cmd=bb handler=f702308e
reg idx=7 cmd=bc handler=f70230ae
reg idx=8 cmd=11 handler=f702763a
reg idx=9 cmd=12 handler=f702765c
reg idx=10 cmd=35 handler=f70278a8
reg idx=11 cmd=4 handler=f7021ece
reg idx=12 cmd=30 handler=f7021e98
reg idx=13 cmd=31 handler=f7021ea8
reg idx=14 cmd=40 handler=f7021eac
reg idx=15 cmd=f9 handler=f7021f58
Starting task scheduler ...
boot bl33 !
env_init: Environment nowhere init done (ret=0)


U-Boot 2019.01 (Oct 18 2022 - 03:37:05 -0400)

DRAM:  8 GiB
Relocation Offset is: df5d2000
Relocating to df5d2000, new gd at d95c1dc8, sp at d95c1db0
board init
watchdog disable
gpio: pin GPIOT_15 (gpio 106) value is 1
fusb302_init: Device ID: 0x91
CC connected in 1 as UFP
fusb302 detect chip.port_num = 0
gpio: pin GPIOH_4 (gpio 152) value is 1
gpio: pin GPIOT_15 (gpio 106) value is 0
gpio: pin GPIOH_3 (gpio 151) value is 0
Setting bus to 6
[meson_mmc_probe]sd: Controller probe success!
[meson_mmc_probe]emmc: Controller probe success!
emmc: resp timeout, cmd8, status=0x1cf2800
emmc: resp timeout, cmd55, status=0x1cf2800
store flag: 0, types: 1
emmc init success!
boot_device:1
boot_seq:0
boot_bakups:3
rebuid_id :0
boot area list: 
       bl2           200         40000
      bl2e         40200         13000
      bl2x         53200         11000
    ddrfip         64200         40000
    devfip         a4200        300000
emmc: tuning start:
emmc: best_win_start =5, best_win_size =5
emmc: clk = 10000206, dly1 = 0, dly2 = 0, adj = 12000, cfg = 804872
fill_ept_by_gpt: invalid gpt
check_valid_dts: FDT_ERR_BADMAGIC
get_partition_from_dts() 232: ret -9
get_partition_from_dts() 235: ret -9
get_ptbl_from_dtb()-372: get partition table from dts faild
mmc_device_init()-1474: get partition table from dtb failed
get_ptbl_rsv()-637: magic faild MPT,    
mmc_device_init()-1508: dtb&rsv are not exist, no LPT source
emmc probe success
In:    serial@8000
Out:   serial@8000
Err:   serial@8000
board common misc_init
board late init
upgrade_step 0
the dtb partition size is:40000   byte
_verify_dtb_checksum()-2947: calc 0, store 0
update_dtb_info()-3055: cpy 1 is not valid
_verify_dtb_checksum()-2947: calc 0, store 0
update_dtb_info()-3055: cpy 0 is not valid
dtb_read()-3162: total valid 0
Err imgread(L349):Fail read dtb from rsv with sz 0x40000
Err imgread(L393):Fail read dtb from _aml_dtb, ret -350
Load DTB from eMMC (1:1) ...
154017 bytes read in 3 ms (49 MiB/s)
vpu: find AML_VPU_CLK_LEVEL_DFT: 7
vpu: clk_level in dts: 7
vpu: vpu_power_on_new
vpu: set clk: 666667000Hz, readback: 666666667Hz(0x100)
vpu: vpu_module_init_config
vpu: vpu_probe
limit_res_1080p: 0
enc_idx: 2
vpp: vpp_init, chip_id=54
vpp: set_osd1_rgb2yuv rgb2yuv on = 0..............
vpp: set_osd2_rgb2yuv rgb2yuv on = 0..............
vpp: set_osd3_rgb2yuv rgb2yuv on = 0..............
vpp: T7 osd4 matrix rgb2yuv..............
hdr_func: 0x8, hdr_process_select 0x20000001
hdr_func: hdr_process_select = 536870913
hdr_func: 0x100, hdr_process_select 0x20000001
hdr_func: hdr_process_select = 536870913
hdr_func: 0x200, hdr_process_select 0x20000001
hdr_func: 0x1, hdr_process_select 0x1
hdr_func: 0x2, hdr_process_select 0x1
rx trim:0x1
LCD_RESET PIN: 0
lcd: lcd_debug_print flag: 0
lcd: [0]: detect mode: tablet, key_valid: 0, clk_path: 0
lcd: config load from dts
lcd: [0]: use panel_type=mipi_0
lcd: load dts config: TS050, lcd_type: mipi(3)
lcd: [0]: TS050, mipi, 8bit, 1080x1920
lcd: [1]: detect mode: tablet, key_valid: 0, clk_path: 0
lcd: config load from dts
lcd: [1]: use panel1_type=vbyone_1
lcd: load dts config: public_1region, lcd_type: vbyone(2)
lcd: [1]: lcd_clk is 0, default to 60Hz
lcd: [1]: public_1region, vbyone, 10bit, 3840x2160
lcd: [2]: detect mode: tablet, key_valid: 0, clk_path: 0
lcd: config load from dts
lcd: [2]: use panel2_type=lvds_1
lcd: load dts config: 1080p-hfreq_hdmi, lcd_type: lvds(1)
lcd: [2]: lcd_clk is 0, default to 60Hz
lcd: [2]: 1080p-hfreq_hdmi, lvds, 8bit, 1920x1080
bl: find en_sequence_reverse: 0
bl: [0]: name: backlight_pwm, method: 1
buff: 905660110961151a
Net:   pwr up eth
ex-phy
chip num 3
set rgmii
Setting bus to 6
[KM]Msg:key_num: 22
[KM]Msg:normal key used!
the key partition size is:40000   byte
calc 0, store 0
cpy 1 is not valid
calc 0, store 0
cpy 0 is not valid
[KM]Msg:mark is not found
[EFUSE_MSG]keynum is 4
MACADDR:02:ad:36:01:33:25(from sec_reg)
eth0: ethernet@fdc00000
recovery_status=
upgrade_step=0
check_display reboot_mode : ,powermode : on
do_hpd_detect, hpd_state=0
vout_hdmi_hpd: lcd no need hpd detect
vout_hdmi_hpd: hdmimode=1080p60hz
vout_hdmi_hpd: colorattribute=444,8bit
no sink, fallback to <NULL>[4]
hdr mode is 0
dv  mode is ver:0  len: 0
hdr10+ mode is 0
HDMI HPD low, no need parse EDID
dolby_vision_process: hpd_state=0
dolby_status 0 1
dolby_vision_process: no tv and dv disabled
Unknown command 'saveenv' - try 'help'
[OSD]load fb addr from dts:/fb
[OSD]status disabled
[OSD]load fb addr from dts:/drm-vpu
[OSD]set initrd_high: 0x3f800000
[OSD]fb_addr for logo: 0x3f800000
[OSD]load fb addr from dts:/fb
[OSD]status disabled
[OSD]load fb addr from dts:/drm-vpu
[OSD]fb_addr for logo: 0x3f800000
[OSD]VPP_OFIFO_SIZE:0xfff01fff
dolby_status 0 1
card in
1080138 bytes read in 11 ms (93.6 MiB/s)
[OSD]osd_hw.free_dst_data: 0,1919,0,1079
[OSD]osd0_update_disp_freescale_enable
is_osd2_configed ret=0
[OSD]osd_hw.free_dst_data: 0,1919,0,1079
[OSD]osd1_update_disp_freescale_enable
[OSD]osd_hw.free_dst_data: 0,1919,0,1079
[OSD]osd0_update_disp_freescale_enable
is_osd2_configed ret=1
set hdmitx VIC = 16 CS = 2 CD = 4
aml_audio_init
configure venc
configure VIC16 timing
hdmitx_check_frac_rate: frac_rate:1
config HPLL = 5940000 frac_rate = 1
clocks_set_vid_clk_div_for_hdmi[526] div = 6
configure hdmitx21
div40: 0
hdmi_tx_set: save mode: 1080p60hz, attr: 444,8bit, hdmichecksum: <NULL>
do_hpd_detect, hpd_state=0
vout_hdmi_hpd: lcd no need hpd detect
vout_hdmi_hpd: hdmimode=1080p60hz
vout_hdmi_hpd: colorattribute=444,8bit
osd: hpd_state=0
[OSD]load fb addr from dts:/fb
[OSD]status disabled
[OSD]load fb addr from dts:/drm-vpu
[OSD]fb_addr for logo: 0x3f800000
[OSD]load fb addr from dts:/fb
[OSD]status disabled
[OSD]load fb addr from dts:/drm-vpu
[OSD]fb_addr for logo: 0x3f800000
1080138 bytes read in 11 ms (93.6 MiB/s)
[OSD]osd_hw.free_dst_data: 0,1919,0,1079
[OSD]osd0_update_disp_freescale_enable
is_osd2_configed ret=1
[OSD]osd_hw.free_dst_data: 0,1919,0,1079
[OSD]osd0_update_disp_freescale_enable
is_osd2_configed ret=1
set hdmitx VIC = 16 CS = 2 CD = 4
aml_audio_init
configure venc
configure VIC16 timing
hdmitx_check_frac_rate: frac_rate:1
config HPLL = 5940000 frac_rate = 1
clocks_set_vid_clk_div_for_hdmi[526] div = 6
configure hdmitx21
div40: 0
hdmi_tx_set: save mode: 1080p60hz, attr: 444,8bit, hdmichecksum: <NULL>
dolby_status 0 1
dolby_status 0 1
hdr_packet
vpp: hdr_policy = 0
vpp: Rx hdr_info.hdr_sup_eotf_smpte_st_2084 = 0
Setting bus to 6
normal power on
Setting bus to 6
boot wol: disable
Setting bus to 6
s_version: 01.01.221018.033705
[KM]Msg:key_num: 22
[EFUSE_MSG]keynum is 4
[KM]Error:f[key_manage_query_size]L401:key[region_code] not programed yet
[KM]Error:f[key_manage_query_size]L401:key[deviceid] not programed yet
Setting bus to 6
usid=25a0000a3a
usid=25a0000a3a
Setting bus to 6
mac=c8:63:14:72:88:9f
gpio: pin GPIOD_4 (gpio 61) value is 1
reboot_mode : cold_boot
cold boot: ffv_wake=off powermode=on suspend=off
Hit SPACE in 2 seconds to stop autoboot
starting USB...
USB0:   Register 1000120 NbrPorts 1
Starting the controller
USB XHCI 1.10
USB1:   No ----gpio-vbus-power
Register 2000120 NbrPorts 1
Starting the controller
USB XHCI 1.10
scanning bus 0 for devices... 1 USB Device(s) found
scanning bus 1 for devices... 3 USB Device(s) found
       scanning usb for storage devices... 1 Storage Device(s) found

Device 0: Vendor: SABRENT  Rev: 0    Prod: ASM225CM        
            Type: Hard Disk
            Capacity: 976762.3 MB = 953.8 GB (2000409264 x 512)
... is now current device
Scanning usb 0:1...
card in
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
emmc: resp timeout, cmd8, status=0x1cf2800
emmc: resp timeout, cmd55, status=0x1cf2800
emmc: tuning start:
emmc: best_win_start =5, best_win_size =5
emmc: clk = 10000206, dly1 = 0, dly2 = 0, adj = 12000, cfg = 804872
fill_ept_by_gpt: invalid gpt
check_valid_dts: FDT_ERR_BADMAGIC
get_partition_from_dts() 232: ret -9
get_partition_from_dts() 235: ret -9
get_ptbl_from_dtb()-372: get partition table from dts faild
mmc_device_init()-1474: get partition table from dtb failed
get_ptbl_rsv()-637: magic faild MPT,    
mmc_device_init()-1508: dtb&rsv are not exist, no LPT source
switch to partitions #0, OK
mmc1(part 0) is current device
Scanning mmc 1:1...
Found /extlinux/extlinux.conf
Retrieving file: /extlinux/extlinux.conf
186 bytes read in 1 ms (181.6 KiB/s)
Retrieving file: /splash.bmp
1:	Default
Enter choice: 1:	Default
Retrieving file: /initrd.img
10189350 bytes read in 74 ms (131.3 MiB/s)
Retrieving file: /Image
25817096 bytes read in 185 ms (133.1 MiB/s)
Retrieving file: /dtb/amlogic/kvim4.dtb
154017 bytes read in 3 ms (49 MiB/s)
Retrieving file: /dtb/amlogic/kvim4.dtb.overlay.env
14 bytes read in 2 ms (6.8 KiB/s)
MIPI LCD not exist, disable lcd node.
Retrieving file: /uEnv.txt
396 bytes read in 1 ms (386.7 KiB/s)
Import user vars: /uEnv.txt 396 bytes
## Error inserting "bootargs" variable, errno=12
append: <NULL>
load dtb from 0x1000000 ......
## Flattened Device Tree blob at 01000000
   Booting using the fdt blob at 0x1000000
   Loading Ramdisk to 3ee48000, end 3f7ffa26 ... OK
   reserving fdt memory region: addr=1000000 size=8b000
   Loading Device Tree to 000000001ff72000, end 000000001fffffff ... OK
Can't find bootargs property in chosen
Enable kaslr

Starting kernel ...

uboot time: 13552031 us
boot 64bit kernel

With a different sd-card, formatted with the ‘SD Card Formatter’, the system booted up without issue. I guess having multiple partitions on the sd-card is causing the issue.

Thanks.

9

Some errors occurred. What you used this SD card before?

10

As best I can remember, the SanDisk Ultra 256GB card was purchased about a month ago. I never used it for booting the OS. I did reformat the original primary partition from fat32 to ext4 immediately. I used it this way for a few weeks until I had the bad idea to break it up into four partitions so I could mount each partition to a different point in the file system. For example, the first partition mounted to /var/www/html to place my wordpress instance onto the SD card. To do this, I first shrunk the ext4 file system in the partition using resize2fs, then I shrunk the partition with fdisk (you need to delete it and recreate it at the same starting location but with a smaller size). I then created three more partitions while still in fdisk. Using resize2fs, I then expanded the ext4 file system in partition 1 and formatted the three new partitions to ext4. All was okay and I resumed development of my Wordpress site with mmcblk1p1 mounted as it was before only now it was smaller. Rebooting always worked but a few days later I powered off the system only to discover it didn’t start up anymore. After some troubleshooting I discovered that it could start up if I removed the SD card and inserting it after start up I could use the system as normal (even warm boots).

Now I believe that there is a problem with the latest ubuntu server image and/or latest updates that is being highlighted by my multiple partition SD card. Or maybe, the boot loader isn’t configured in a way to understand multiple partitions. The fact that the Ubuntu had no trouble with the SD card tells me the trouble lies with the boot loader.

As a frustrating side note, none of the dumps I made of my system since starting to use the latest image can be used now. All of them, four in total, verify ok and write back successfully but fail to boot. I’ve lost days of work. Also, my last dump of the previous image isn’t working either. I’m still investigating the situation, but I suspect that my use of ‘full-upgrade’ is installing some updates that are harmful. Using just ‘update’ seems to hold back udev and some other library and doesn’t install something to do with ‘-hwe-’. I’ll make a new post once I’ve have more information.

Thanks for your time.

11

I tried a SD card with multiple partitions on my side, but I can’t preproduce the issue.

Can you use another SD card to reproduce this issue on your side?

12

I was able to reproduce the error using a different SD card, an ADATA SDXC 64GB.
The steps I took are:

  1. install latest ubuntu server image (Oct 18)
  2. update & upgrade (some upgrades were held back), warm reboot, cold boot
  3. update & upgrade (held back upgrades were installed except tzdata which was still held back), warm reboot, cold boot - AT THIS POINT VIM4 fails to boot with my original SD card (cold boot)
  4. update & full-upgrade (nothing installed, tzdata held back), warm reboot, cold boot
  5. New SD card formatted in Windows 11 using SD Card Formatter.
  6. Inserted SD card into VIM4, cold boot success
  7. fdisk /dev/mmcblk1
  • d delete partition,
  • n new partition primary +32GiB,
  • n new partition primary +16GiB,
  • n new partition primary +8GiB,
  • n new partition primary (remainder of space)
  • w
  1. warm reboot - SUCCESS
  2. cold boot after poweroff command - FAIL

Same issue as seen in the above log.

The held back packages on the first upgrade are: libudev1 tzdata udev
Everything is okay at this point

The second upgrade installs nothing.

The third upgrade (with full-upgrade) installs new systemd-hwe-hwdb, and libudev1, udev. tzdata is kept back. One of these three packages is causing the issue because from this point forward the system fails to boot from a power off state with either of my SD cards inserted.

NOW all this is no longer an issue for me as I’ve decided that having multiple partitions on my SD card is a bad idea. I’ve since learned that I can achieve my goal using bind mounts and use my SD card with only one big partition. The system cold boots fine that way.

The bigger issue for me at the moment is why my old dumps are not working. The log shows a problem with tzdata. I’ll make a new post for that problem.

Thanks again for your time.

13

Hello @pixelgazer

We will try to reproduce this issue on our side.