VIM: spurious suspend under Buildroot


#1

I have developed a small application running with Amlogic’s Buildroot on VIM. From time to time, an unexpected CPU suspend is issued:

[19201.564788@0] codec:audio pts started::::::: 1
bl30 get wakeup sources!
process command 00000006
bl30 enter suspend!
cpu clk suspend rate 1000000000
suspend_counter: 1
Enter ddr suspend
first time suspend
ddr suspend time: 1887us
store restore gp0 pll
process command 00000001
CEC cfg:0x0000
set vddee to 0x035cmv
08915d0000000000exit_reason:0x06
set vddee to 0x03e8mv
set vcck to 0x0460mv
store restore gp0 pll
gp0 pll can't lock
read gp0_ctrl 40000000
read gp0_ctrl2 0
read gp0_ctrl3 0
read gp0_ctrl4 0
Enter ddr resume
ddr resume time: 372us
cfg15 3b01000
cfg15 63b01000
cpu c[20192.850197@0] [aml_is_card_insert] card OUT
[20192.850334@0] usb 1-1: USB disconnect, device number 2

#
#
#
#
# lk resume rate 1000000000
[20192.950090@0] aml_spdif_dai: aiu 958 playback disable

If the power button of the VIM is used to wake up the board (from exit_reason:0x06 in the log above), then the system does not work properly because Linux has not gone through a proper suspend/resume sequence.

This could be caused by a spurious call to cpu_suspend in the kernel, or by something in bl30.bin, but there are no source files for it. Any idea?

For reference, a suspend generated on purpose with the power button looks like the log below, and everything works fine after resumption:

[  296.116223@0] codec:audio pts started::::::: 1

# [  322.389481@0] input input1: key 116 down
[  322.569436@0] input input1: key 116 up
[  322.570001@0] request_suspend_state: sleep (3->3) at 322540682652 (2015-01-01 00:43:51.845296026 UTC)
[  322.576720@0] request_suspend_state,164,old_sleep=0,new_state=3
[  322.582694@0] early_suspend: call handlers
[  322.609401@0] avmute set to 2
[  322.711654@0] hdmitx: system: HDMITX: early suspend
[  322.711702@0] hdmitx: system: unmux DDC for gpio read edid
[  322.716364@0]
[  322.716364@0] vdac_enable: on:0,module_sel:8
[  323.729366@0] stop_drawing_early_suspend: timeout waiting for userspace to stop drawing
[  323.731992@0] fb: osd_suspended
[  323.734884@0] gxbb_pm: meson_system_early_suspend
[  323.740606@0] early_suspend: sync
[  323.751453@0] PM: suspend entry 2015-01-01 00:43:53.026747485 UTC
[  323.751974@0] PM: Syncing filesystems ... done.
[  323.830231@0] Freezing user space processes ... (elapsed 0.001 seconds) done.
[  323.831717@0] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[  323.839821@0] force to skip cfg80211_leave_all due to wifi suspend/resume issue
[  323.846514@0] bcmsdh_sdmmc_suspend Enter func->num=2
[  323.851434@0] bcmsdh_sdmmc_suspend Exit
[  323.855184@0] bcmsdh_sdmmc_suspend Enter func->num=1
[  323.891152@0] aml_spdif_dai: aiu 958 playback disable
[  323.891199@0] aml_snd_card: enter aml_suspend_pre
[  323.896333@0] aml_T9015_audio_suspend!
[  323.898970@0] aml_snd_card: enter aml_suspend_post
[  323.903925@0] amvecm: suspend module
[  323.907260@0] vdin_drv_suspend ok.
[  323.910622@0] vdin_drv_suspend ok.
[  323.914238@0] sysled: module suspend ok
[  323.917809@0] meson-remote c8100580.rc: remote suspend
[  323.923008@0] PM: suspend of devices complete after 83.261 msecs
[  323.928799@0] gxbb_pm: enter meson_pm_prepare!
[  323.933659@0] di: di_suspend
[  323.936124@0] PM: late suspend of devices complete after 2.928 msecs
[  323.943069@0] PM: noirq suspend of devices complete after 0.702 msecs
[  323.948738@0] Disabling non-boot CPUs ...
[  323.952779@0] gxbb_pm: enter meson_pm_suspend!
[  323.952779@0] gxbb_pm: late_suspend: call handlers
[  323.952779@0] gxbb_pm: late_suspend: sync
bl30 get wakeup sources!
process command 00000006
bl30 enter suspend!
cpu clk suspend rate 1000000000
suspend_counter: 1
Enter ddr suspend
first time suspend
ddr suspend time: 1886us
store restore gp0 pll
process command 00000001
CEC cfg:0x0000
set vddee to 0x035cmv
08915d0000000000exit_reason:0x06
set vddee to 0x03e8mv
set vcck to 0x0460mv
store restore gp0 pll
gp0 pll can't lock
read gp0_ctrl 40000000
read gp0_ctrl2 0
read gp0_ctrl3 0
read gp0_ctrl4 0
Enter ddr resume
ddr resume time: 372us
cfg15 3b00000
cfg15 63b00000
[  323.952779@0] gxbb_pm: late_resume: ccall handlers
[  323.952779@0] gxbb_pm: late_resume: done
[  323.952779@0] gxbb_pm: ... wake up
[  323.953317@0] PM: noirq resume of devices complete after 0.464 msecs
[  323.959189@0] [aml_is_card_insert] card OUT
[  323.963325@0] di: resume module
[  323.966596@0] PM: early resume of devices complete after 3.327 msecs
[  323.972551@0] gxbb_pm: enter meson_pm_finish!
[  323.978736@0] meson-remote c8100580.rc: remote resume
[  323.981909@0] input input1: key 116 down
[  323.985853@0] meson-remote c8100580.rc: default protocol = 0x1 and id = 0
[  323.992449@0] meson-remote c8100580.rc: reg=0x0, val=0x1f40190
[  323.998227@0] meson-remote c8100580.rc: reg=0x4, val=0x12c00c8
[  324.004006@0] meson-remote c8100580.rc: reg=0x8, val=0x960050
[  324.009698@0] meson-remote c8100580.rc: reg=0xc, val=0x480028
[  324.015391@0] meson-remote c8100580.rc: reg=0x10, val=0x70fa0013
[  324.021342@0] meson-remote c8100580.rc: reg=0x18, val=0x8616800
[  324.027207@0] meson-remote c8100580.rc: reg=0x1c, val=0x9f00
[  324.032813@0] meson-remote c8100580.rc: reg=0x20, val=0x0
[  324.038161@0] meson-remote c8100580.rc: reg=0x24, val=0x0
[  324.043508@0] meson-remote c8100580.rc: reg=0x28, val=0x0
[  324.049731@0] sysled: module resume ok
[  324.052642@0] vdin_drv_resume ok.
[  324.055847@0] vdin_drv_resume ok.
[  324.059152@0] amvecm: resume module
[  324.062637@0] amhdmitx: resume module 3687
[  324.066673@0] meson_uart c81004e0.serial: ttyS4 use xtal(8M) 24000000 change 19200 to 19200
[  324.074996@0] aml_snd_card: enter aml_resume_pre
[  324.079497@0] aml_T9015_audio_resume!
[  324.084117@0] gpio keypad wakeup
pu clk resume rate 1000000000
[  324.129294@0] input input1: key 116 up
[  324.160364@0] libphy: set driving length c
[  324.160465@0] libphy: set PLL minimum jitter
[  324.288078@0] emmc: trying cali 0-th time(s)
[  324.289820@0] aml_snd_card: enter aml_resume_post
[  324.296584@0] emmc: delay[0]=  800 padding= 1, bidx=0
[  324.296609@0] emmc: delay[1]= 1400 padding= 3, bidx=1
[  324.301395@0] emmc: delay[2]=  800 padding= 1, bidx=0
[  324.306396@0] emmc: delay[3]= 1200 padding= 4, bidx=1
[  324.311418@0] emmc: delay[4]= 1200 padding= 4, bidx=1
[  324.316400@0] emmc: delay[5]=  800 padding= 1, bidx=0
[  324.321398@0] emmc: delay[6]= 1200 padding= 4, bidx=1
[  324.326404@0] emmc: delay[7]= 1000 padding= 5, bidx=1
[  324.331403@0] emmc: calibration result @ 0: max(1400), min(800)
[  324.337272@0] emmc: line_delay =0x21311303, max_cal_result =1400
[  324.343484@0] emmc: base_index_max 1, base_index_min 0
[  324.348322@0] emmc: clk 100000000 SDR mode tuning start
[  324.353899@0] emmc: rx_tuning_result[0] = 10
[  324.358067@0] emmc: rx_tuning_result[1] = 10
[  324.362315@0] emmc: rx_tuning_result[2] = 10
[  324.366518@0] emmc: rx_tuning_result[3] = 10
[  324.370781@0] emmc: rx_tuning_result[4] = 10
[  324.374678@0] [mmc_cmd_LBA_show] emmc: cmd 21, arg 0x13800, operation is in [reserved] disk!
[  324.383370@0] emmc: rx_tuning_result[6] = 10
[  324.387565@0] emmc: rx_tuning_result[7] = 10
[  324.391795@0] emmc: rx_tuning_result[8] = 10
[  324.396013@0] emmc: rx_tuning_result[9] = 10
[  324.399914@0] emmc: best_win_start =6, best_win_size =9
[  324.405053@0] emmc: sd_emmc_regs->gclock=0x100024a,sd_emmc_regs->gadjust=0x2000
[  324.412318@0] emmc: gclock =0x100024a, gdelay=0x21311303, gadjust=0x2000
[  324.419131@0] emmc: support driver strength type 1
[  324.423797@0] emmc: try set sd/emmc to DDR mode
[  324.428182@0] emmc: try set sd/emmc to DDR mode
[  324.433232@0] bcmsdh_sdmmc_resume Enter func->num=1
[  324.437509@0] bcmsdh_sdmmc_resume Enter func->num=2
[  324.442330@0] bcmsdh_sdmmc_resume Exit
[  324.753179@0] usb 1-1: reset high-speed USB device number 2 using xhci-hcd
[  324.754436@0] xhci-hcd xhci-hcd.0.auto: Setup ERROR: setup context command for slot 1.
[  324.879324@0] usb 1-1: reset high-speed USB device number 2 using xhci-hcd
[  324.880571@0] xhci-hcd xhci-hcd.0.auto: Setup ERROR: setup context command for slot 1.
[  324.999323@0] usb 1-1: reset high-speed USB device number 2 using xhci-hcd
[  325.019443@0] xhci-hcd xhci-hcd.0.auto: xHCI xhci_drop_endpoint called with disabled ep ffffffc058519640
[  325.149649@0] PM: resume of devices complete after 1172.782 msecs
[  325.152154@0] Restarting tasks ...
[  325.154961@0] aml_spdif_dai: aml_hw_iec958_init,runtime->rate=44100, same source mode(0)
[  325.163048@0] request_suspend_state: wakeup (3->0) at 325133780903 (2015-01-01 00:59:07.366086003 UTC)
[  325.170807@0] request_suspend_state,164,old_sleep=1,new_state=0
[  325.176667@0] wakeup wake lock: main
[  325.183106@0] done.
[  325.183362@0] fb: osd_open index=0,open_count=3
[  325.186883@0] PM: suspend exit 2015-01-01 00:59:07.389928712 UTC
[  325.193264@0] aml_spdif_dai: set normal 512 fs /4 fs

Here, the Linux suspend/resume operations are properly executed, and the values of cfg15 are different from those of the spurious case, but I don’t know what they mean.


#2

Hi BenTh.WS,

Which version of Buildroot did you use?

Yes, we don’t have source code for bl30.bin.


#3

I used buildroot_openlinux_kernel_4.9_wayland_20170814.tar.gz with the mesongxl_p212_32 configuration and the patches from Port Buildroot on Khadas VIM.

Can you give a list of all the possible causes of CPU suspend (besides the power button)?


#4

Hi BenTh.WS,

I’ve not try mesongxl_p212_32 configuration yet, maybe you can try some 64bit configurations like mesongxl_p212_release? Good luck!:smiley:

Thanks.


#5

Hi numbqq,

The 64-bit configurations are not appropriate for my application because I need to be able to use AC-3 and DTS passthrough on S/PDIF with the Amlogic library used by kplayer (i.e. libplayer), and it turns out that this feature requires libraries provided only as 32-bit binary files without the source code (multimedia/libplayer/src/audio_codec/libeac3/libdcv.so and multimedia/libplayer/src/audio_codec/libdtscore/libdtscore.so). So I can test the 64-bit configurations only if you can provide me with either the source code of these libraries or 64-bit binaries. Maybe Amlogic can accept to provide this.

Why is the source code of bl30.bin closed? As customers, we should be able to do what we want with this platform. Only the encryption keys and a few licensed parts of the code should be kept secret. The source code of bl301.bin is provided for the ODROID-C2 (https://github.com/hardkernel/u-boot_firmware/tree/odroidc2-bl301), and the source code of ARM Trusted Firmware is provided for many platforms (https://github.com/ARM-software/arm-trusted-firmware/tree/master/plat), so why is Amlogic keeping this secret? See also the ARM Trusted Firmware thread and http://www.fredericb.info/2016/10/amlogic-s905-soc-bypassing-not-so.html. I only want to know the possible causes of this spurious suspend. What is cfg15 in my log?


#6

Hi BenTh.WS,

Maybe you should add power key support, for buildroot this is missing. You can refer the following commit to add power key support.

Thanks.


#7

Hi numbqq,

No, this change is already in Amlogic’s Buildroot, in gxl_p212_2g_buildroot.dts.

However, the following commit is present in the Nougat branch for KVIM, but not in Amlogic’s Buildroot:


Why was this change introduced for KVIM?

Maybe there are other required changes for KVIM, such as inputs used on the P212 that are floating on the KVIM and might trigger unwanted behaviors. I will check the differences.

Also, I’ve just noticed that the FIP files (bl*.bin) in U-Boot are different between Amlogic’s Buildroot and KVIM’s Nougat. What are the differences? Are there any important changes for KVIM? Is it safe to use KVIM’s Nougat FIP files with Buildroot?


#8

Hi BenTh.WS,

The u-boot and kernel from Android are different from Amlogic Buildroot, we don’t have rights to Amlogic’s Buildroot repo, so we don’t know the details, too.

Thanks.


#9

Hi numbqq,

For the record, Amlogic’s Buildroot sets the CPU0 frequency scaling governor to hotplug, while Nougat for KVIM sets it to interactive, so I tried interactive with Buildroot, and so far it has worked flawlessly during the whole weekend. So the root cause must be a bug in Amlogic’s Linux with the hotplug governor.


#10

Hi, this is from include/linux/amlogic/pm.h

#define	UDEFINED_WAKEUP	0
#define	CHARGING_WAKEUP	1
#define	REMOTE_WAKEUP		2
#define	RTC_WAKEUP			3
#define	BT_WAKEUP			4
#define	WIFI_WAKEUP			5
#define	POWER_KEY_WAKEUP	6
#define	AUTO_WAKEUP			7
#define	CEC_WAKEUP			8
#define	REMOTE_CUS_WAKEUP		9

Although I don’t know what is REMOTE_CUS_WAKEUP (customer remote wakeup) and what is the difference against REMOTE_WAKEUP!