Wind River Support Network

HomeDefectsLIN1021-212
Fixed

LIN1021-212 : "sleepgraph -m mem -rtcwake 60 -o suspend/" failed parse suspend log on NUC7 target

Created: May 20, 2021    Updated: Jul 12, 2021
Resolved Date: Jul 4, 2021
Found In Version: 10.21.20.1
Fix Version: 10.21.20.2
Severity: Standard
Applicable for: Wind River Linux LTS 21
Component/s: BSP

Description

root@intel-x86-64:~# sleepgraph -m mem -rtcwake 60 -o suspend_proc -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc
Checking this system (intel-x86-64)...
 have root access: YES
 is sysfs mounted: YES
 is "mem" a valid power mode: YES
 is ftrace supported: YES
 are kprobes supported: YES
 timeline data source: FTRACE (all trace events found)
 is rtcwake supported: YES
baseboard-manufacturer : Intel Corporation
baseboard-product-name : NUC7i5DNB
baseboard-serial-number : BTDN824006WT
baseboard-version : J57626-507
bios-release-date : 05/28/2018
bios-vendor : Intel Corp.
bios-version : DNKBLi5v.86A.0044.2018.0528.1719
chassis-manufacturer : Intel Corporation
chassis-version : 2
processor-manufacturer : Intel(R) Corporation
processor-version : Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz
system-manufacturer : Intel Corporation
system-product-name : NUC7i5DNKE
system-serial-number : DW1703478100072
system-version : J72865-507
cpucount : 4
memtotal : 7717732 kB
memfree : 7046220 kB
INITIALIZING FTRACE...
Setting trace buffers to 65536 kB (16384 kB per cpu)
INITIALIZING KPROBES...
START TRACING
SUSPEND START
will issue an rtcwake in 60 seconds
[ 128.576316] PM: suspend entry (deep)
[ 128.581123] Filesystems sync: 0.001 seconds
[ 128.593682] Freezing user space processes ... (elapsed 0.003 seconds) done.
[ 128.603832] OOM killer disabled.
[ 128.607118] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 128.616738] printk: Suspending console(s) (use no_console_suspend to debug)
[ 128.646762] serial 00:01: disabled
[ 128.703807] e1000e: EEE TX LPI TIMER: 00000011
[ 128.888838] ACPI: EC: interrupt blocked
[ 129.060389] ACPI: Preparing to enter system sleep state S3
[ 129.065722] ACPI: EC: event blocked
[ 129.065728] ACPI: EC: EC stopped
[ 129.065733] PM: Saving platform NVS memory
[ 129.065821] Disabling non-boot CPUs ...
[ 129.068934] IRQ 132: no longer affine to CPU1
[ 129.070205] smpboot: CPU 1 is now offline
[ 129.073516] IRQ 133: no longer affine to CPU2
[ 129.074795] smpboot: CPU 2 is now offline
[ 129.078112] IRQ 131: no longer affine to CPU3
[ 129.079263] smpboot: CPU 3 is now offline
[ 129.082650] ACPI: Low-level resume complete
[ 129.082863] ACPI: EC: EC started
[ 129.082867] PM: Restoring platform NVS memory
[ 129.105277] Enabling non-boot CPUs ...
[ 129.105556] x86: Booting SMP configuration:
[ 129.105563] smpboot: Booting Node 0 Processor 1 APIC 0x2
[ 129.108318] CPU1 is up
[ 129.108504] smpboot: Booting Node 0 Processor 2 APIC 0x1
[ 129.111950] CPU2 is up
[ 129.112111] smpboot: Booting Node 0 Processor 3 APIC 0x3
[ 129.114942] CPU3 is up
[ 129.116653] ACPI: Waking up from system sleep state S3
[ 129.335769] ACPI: EC: interrupt unblocked
[ 129.540125] ACPI: EC: event unblocked
[ 129.554484] nvme nvme0: 4/0/0 default/read/poll queues
[ 129.562060] serial 00:01: activated
[ 129.846745] ata1: SATA link down (SStatus 4 SControl 300)
[ 130.111124] acpi LNXPOWER:04: Turning OFF
[ 130.116112] acpi LNXPOWER:02: Turning OFF
[ 130.143023] OOM killer enabled.
[ 130.146410] Restarting tasks ...
[ 130.158383] done.
[ 130.170873] video LNXVIDEO:00: Restoring backlight state
[ 130.176396] PM: suspend exit
[ 130.585307] Writes: Total: 92295717 Max/Min: 13254766/10600589 Fail: 0
[ 135.563086] e1000e 0000:00:1f.6 eth0: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
RESUME COMPLETE
SUSPEND START
will issue an rtcwake in 60 seconds
[ 136.851003] PM: suspend entry (deep)
[ 136.855157] Filesystems sync: 0.000 seconds
[ 136.861746] Freezing user space processes ... (elapsed 0.002 seconds) done.
[ 136.871700] OOM killer disabled.
[ 136.874984] Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
[ 136.885207] printk: Suspending console(s) (use no_console_suspend to debug)
[ 136.913579] serial 00:01: disabled
[ 136.973616] e1000e: EEE TX LPI TIMER: 00000011
[ 137.156278] ACPI: EC: interrupt blocked
[ 137.332637] ACPI: Preparing to enter system sleep state S3
[ 137.339207] ACPI: EC: event blocked
[ 137.339213] ACPI: EC: EC stopped
[ 137.339219] PM: Saving platform NVS memory
[ 137.339331] Disabling non-boot CPUs ...
[ 137.343861] smpboot: CPU 1 is now offline
[ 137.350343] smpboot: CPU 2 is now offline
[ 137.354640] smpboot: CPU 3 is now offline
[ 137.357779] ACPI: Low-level resume complete
[ 137.357991] ACPI: EC: EC started
[ 137.357995] PM: Restoring platform NVS memory
[ 137.358943] Enabling non-boot CPUs ...
[ 137.359357] x86: Booting SMP configuration:
[ 137.359364] smpboot: Booting Node 0 Processor 1 APIC 0x2
[ 137.364410] CPU1 is up
[ 137.365190] smpboot: Booting Node 0 Processor 2 APIC 0x1
[ 137.391297] CPU2 is up
[ 137.391935] smpboot: Booting Node 0 Processor 3 APIC 0x3
[ 137.396486] CPU3 is up
[ 137.397962] ACPI: Waking up from system sleep state S3
[ 137.652140] ACPI: EC: interrupt unblocked
[ 137.855114] ACPI: EC: event unblocked
[ 137.870717] nvme nvme0: 4/0/0 default/read/poll queues
[ 137.876153] serial 00:01: activated
[ 138.172207] ata1: SATA link down (SStatus 4 SControl 300)
[ 138.439256] acpi LNXPOWER:04: Turning OFF
[ 138.444839] acpi LNXPOWER:02: Turning OFF
[ 138.474154] OOM killer enabled.
[ 138.477355] Restarting tasks ...
[ 138.492665] done.
[ 138.508091] video LNXVIDEO:00: Restoring backlight state
[ 138.513482] PM: suspend exit
[ 143.539823] e1000e 0000:00:1f.6 eth0: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
RESUME COMPLETE
CAPTURING DMESG
CAPTURING TRACE
PROCESSING DATA
Traceback (most recent call last):
 File "/usr/bin/sleepgraph", line 6748, in <module>
 ret = runTest()
 File "/usr/bin/sleepgraph", line 5894, in runTest
 testruns, stamp = processData(True)
 File "/usr/bin/sleepgraph", line 5789, in processData
 testruns, error = parseTraceLog(live)
 File "/usr/bin/sleepgraph", line 3165, in parseTraceLog
 proclist[name] = int(val[1])
IndexError: list index out of range
root@intel-x86-64:~#

fixed patch can get from: https://github.com/intel/pm-graph/pull/20

Steps to Reproduce

/lpg-build/cdc/fast_prod/WRL10_21/WRL10_21_GIT/wrlinux-10/setup.sh --machines=intel-x86-64 --templates feature/intel-qat feature/xfce feature/dpdk feature/bsp-extras feature/docker feature/kexec feature/kdump feature/lxc feature/tpm2 --layers meta-dpdk --distro wrlinux-cgl --accept-eula=yes --distro wrlinux-cgl --dl-layers

source environment-setup-x86_64-wrlinuxsdk-linux
source oe-init-build-env build

cpuhotplug_online
cpuidle_function
cpuidle_perf_event
cpuidle_sys_check
dma_kernel_test
docker_check_config
docker_compose_build
docker_compose_ps
docker_compose_scale_down
docker_compose_scale_up
docker_compose_up
docker_helloworld
dpdk_byteorder
dpdk_cycles
dpdk_helloworld
dpdk_l2fwd
dpdk_link_status_interrupt
dpdk_logs_test
dpdk_malloc
dpdk_mbuf
dpdk_memory
dpdk_memzone
dpdk_prefetch
dpdk_rwlock
dpdk_spinlock
dpdk_testpmd
dpdk_unittest_cmdline
dpdk_unittest_crc
dpdk_unittest_lpm
dpdk_unittest_lpm6
dpdk_unittest_metering
dpdk_unittest_red
dpdk_unittest_ring
dpdk_unittest_ring_perf
dpdk_unittest_ring_pmd
dpdk_unittest_scheduler
dpdk_unittest_timer
edac_ctl_test
edac_inject_error
edac_module_test
edac_service_test
edac_sys_check
edac_util_test
ethernet_autoneg_restrict
ethernet_buffer_ring
ethernet_change_speed
ethernet_check_mac
ethernet_coalescing
ethernet_dump_register
ethernet_fping
ethernet_iperf_tcp
ethernet_iperf_udp
ethernet_netperf_tcprr
ethernet_netperf_tcpstream
ethernet_netperf_udprr
ethernet_netperf_udpstream
ethernet_ping
ethernet_sriov
ethernet_statistics
ethernet_vlan_ping
fman_sys_check
gpio_sys_check
graphic_change_resolution
graphic_glxgears
graphic_show_status
graphic_x11perf
graphic_xrandr_show
i2c_sys_check
intel_exploring_test
intel_kvm_sanity
intel_pclmulqdq_check_flag
intel_powerclamp_sys_check
intel_pt_sys_check
intel_rapl_detect
intel_rapl_sys_check
intel_reseeds_check_flags
intel_reseeds_rng_tools
iommu_intel_sanity
kdump_smp_up_systemd
kernwarning_buildcheck
kmod_test
lspci_test
malloc_loop
mces_check_cpu_supported
mdelay_test
microcode_check_device
microcode_check_update
microcode_sys_check
numa_check_support
numa_check_sys
numa_demo
numa_shownodes
numa_stat
pci_hotplug
pci_msi
perf_events_cpu
perf_events_l1_cache
perf_events_ll_cache
perf_events_mem
perf_events_sched
perf_events_syscall
perf_events_syscall_enter
perf_events_syscall_exit
perf_events_timer
perf_events_tlb
perf_events_uncore
perf_events_with_load
pm_basic_sleepgraph
pm_dev_sleepgraph
pm_pmgraph_check
pm_proc_sleepgraph
pm_suspend_sleepgraph
ramspeed
rtc_alarm
rtc_hctosys
rtc_hwclock_selftest
rtc_sys_check
rtc_systohc
rt_cyclictest
rt_hackbench
rt_migrate_test
rt_pi_stress
rt_pmqtest
rt_ptsematest
rt_signaltest
rt_sigwaittest
rt_svsematest
sem_test
serial_getty_tty
storage_aio_stress
storage_bonnie
storage_copy_big_file
storage_dd_100M
storage_dd_1G
storage_dd_500M
storage_dd_5G
storage_fio_flow
storage_fio_latency
storage_fio_randread
storage_fio_rand_rw
storage_fio_randwrite
storage_fio_read
storage_fio_rw
storage_fio_stonewalls
storage_fio_stress
storage_fio_write
storage_fio_zone
storage_hdparm
storage_ionice_bfq
storage_ionice_kyber
storage_ionice_mqdeadline
storage_ionice_none
storage_iozone
storage_nfs_mounts
storage_scheduler_bfq
storage_scheduler_kyber
storage_scheduler_mqdeadline
storage_scheduler_none
storage_sync_big_file
storage_sync_multi_file
storage_tiobench
stress_cpu
stress_cpu_mem_io
stress_io
stress_memory
temp_sensors
temp_sys_check
tpm2
tpm2_abrmd_extended-sessions
tpm2_abrmd_nvundefinespecial
tpm2_abrmd_policyauthorize
tpm2_abrmd_policyauthorizenv
tpm2_abrmd_policyauthvalue
tpm2_abrmd_policycommandcode
tpm2_abrmd_policycountertimer
tpm2_abrmd_policyduplicationselect
tpm2_abrmd_policynamehash
tpm2_abrmd_policynv
tpm2_abrmd_policynvwritten
tpm2_abrmd_policyor
tpm2_abrmd_policypassword
tpm2_abrmd_policysecret
tpm2_abrmd_policysigned
tpm2_abrmd_policytemplate
tpm2_abrmd_policyticket
tpm2_activecredential
tpm2_attestation
tpm2_certify
tpm2_certifycreation
tpm2_changeauth
tpm2_changeeps
tpm2_changepps
tpm2_checkquote
tpm2_clear
tpm2_clearcontrol
tpm2_clockrateadjust
tpm2_create
tpm2_createak
tpm2_createek
tpm2_createpolicy
tpm2_createprimary
tpm2_dictionarylockout
tpm2_duplicate
tpm2_encryptdecrypt
tpm2_evictcontrol
tpm2_flushcontext
tpm2_getcap
tpm2_getekcertificate
tpm2_getrandom
tpm2_gettestresult
tpm2_gettime
tpm2_hash
tpm2_hierarchycontrol
tpm2_hmac
tpm2_import
tpm2_import_tpm
tpm2_incrementalselftest
tpm2_load
tpm2_loadexternal
tpm2_makecredential
tpm2_nv
tpm2_nvcertify
tpm2_nvinc
tpm2_output_formats
tpm2_pcrallocate
tpm2_pcrevent
tpm2_pcrextend
tpm2_pcrlist
tpm2_pcrreset
tpm2_print
tpm2_quote
tpm2_readclock
tpm2_readpublic
tpm2_rsadecrypt
tpm2_rsaencrypt
tpm2_selftest
tpm2_send
tpm2_setclock
tpm2_setprimarypolicy
tpm2_sign
tpm2_startup
tpm2_stirrandom
tpm2_testparms
tpm2_unseal
tpm2_verifysignature
turbostat_test
usb_show_device
watchdog_check_device
watchdog_check_node
watchdog_get_monitor
watchdog_get_status
watchdog_keep_alive
watchdog_magic_close
watchdog_set_timeout
watchdog_sys_check
wifi_basic_func
wireless_lxc_namespace
[Test_HW]
" > customized_test_plan.ini

bitbake-layers add-layer /lpg-build/cdc/WASSP_LINUX_MASTER_WR/testcases/wrlinux/wr-testing/bts-dev && echo require templates/feature/bts/template.conf >> conf/local.conf && echo IMAGE_FSTYPES += \" tar.bz2\" >> conf/local.conf &&echo BB_NO_NETWORK_pn-lmbench = \"0\" >> conf/local.conf &&echo ACTIVE_PLAN = \"customized_test_plan.ini\" >> conf/local.conf &&echo IMAGE_FSTYPES_remove = \" live hddimg iso\" >>conf/local.conf

bitbake wrlinux-image-std

/opt/wr-test/main_test.py -k pm_proc_sleepgraph:
Live chat
Online