Linux/TCI6630K2L: Incomprehensible CPU usage reporting

Shinha

Part Number: TCI6630K2L
Other Parts Discussed in Thread: RFSDK

Tool/software: Linux

Hi,

We have been facing an issue of incorrect CPU usage of a ARM core on our board based on K2L (2 ARM Cores and 4 DSP cores).

We are using kernel version is K2_LINUX_03.10.10

TOP report more than 70% usage on Cpu1, but I cannot find any task using high load.(refer to the following capture and attache log file: 0.5sec interval reporting)

===========

[Fri Aug 18 10:54:29.547 2017] top - 10:53:27 up 65 days, 22 min, 1 user, load average: 0.84, 0.91, 0.95
[Fri Aug 18 10:54:29.547 2017] Tasks: 87 total, 1 running, 86 sleeping, 0 stopped, 0 zombie
[Fri Aug 18 10:54:29.547 2017] Cpu0 : 2.2%us, 6.5%sy, 0.0%ni, 91.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
[Fri Aug 18 10:54:29.547 2017] Cpu1 : 70.4%us, 5.4%sy, 0.0%ni, 24.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
[Fri Aug 18 10:54:29.547 2017] Mem: 1031956k total, 246592k used, 785364k free, 0k buffers
[Fri Aug 18 10:54:29.547 2017] Swap: 0k total, 0k used, 0k free, 115532k cached
[Fri Aug 18 10:54:29.547 2017]
[Fri Aug 18 10:54:29.547 2017] PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
[Fri Aug 18 10:54:29.547 2017] 2598 root 20 0 10704 536 452 S 2 0.1 96:42.03 gps_monitor
[Fri Aug 18 10:54:29.547 2017] 1 root 20 0 1320 504 440 S 0 0.0 0:43.01 init
[Fri Aug 18 10:54:29.547 2017] 2 root 20 0 0 0 0 S 0 0.0 0:00.00 kthreadd
[Fri Aug 18 10:54:29.578 2017] 3 root 20 0 0 0 0 S 0 0.0 69:18.63 ksoftirqd/0
[Fri Aug 18 10:54:29.578 2017] 5 root 0 -20 0 0 0 S 0 0.0 0:00.00 kworker/0:0H
[Fri Aug 18 10:54:29.578 2017] 7 root RT 0 0 0 0 S 0 0.0 0:09.29 migration/0
[Fri Aug 18 10:54:29.578 2017] 8 root 20 0 0 0 0 S 0 0.0 0:00.00 rcu_bh
[Fri Aug 18 10:54:29.578 2017] 9 root 20 0 0 0 0 S 0 0.0 26:28.68 rcu_sched
[Fri Aug 18 10:54:29.578 2017] 10 root RT 0 0 0 0 S 0 0.0 0:05.53 migration/1
[Fri Aug 18 10:54:29.594 2017] 11 root 20 0 0 0 0 S 0 0.0 4:03.02 ksoftirqd/1
[Fri Aug 18 10:54:29.594 2017] 13 root 0 -20 0 0 0 S 0 0.0 0:00.00 kworker/1:0H
[Fri Aug 18 10:54:29.594 2017] 14 root 0 -20 0 0 0 S 0 0.0 0:00.00 khelper
[Fri Aug 18 10:54:29.594 2017] 15 root 20 0 0 0 0 S 0 0.0 0:00.00 kdevtmpfs
[Fri Aug 18 10:54:29.594 2017] 20 root 20 0 0 0 0 S 0 0.0 50:39.55 kworker/1:1
[Fri Aug 18 10:54:29.594 2017] 240 root 0 -20 0 0 0 S 0 0.0 0:00.00 writeback
[Fri Aug 18 10:54:29.609 2017] 242 root 0 -20 0 0 0 S 0 0.0 0:00.00 bioset
[Fri Aug 18 10:54:29.609 2017] 244 root 0 -20 0 0 0 S 0 0.0 0:00.00 kblockd
[Fri Aug 18 10:54:29.609 2017] 251 root 0 -20 0 0 0 S 0 0.0 0:00.00 ata_sff
[Fri Aug 18 10:54:29.609 2017] 261 root 20 0 0 0 0 S 0 0.0 0:00.00 khubd
[Fri Aug 18 10:54:29.609 2017] 424 root 0 -20 0 0 0 S 0 0.0 0:00.00 rpciod
[Fri Aug 18 10:54:29.625 2017] 436 root 20 0 0 0 0 S 0 0.0 0:00.00 kswapd0
[Fri Aug 18 10:54:29.625 2017] 491 root 20 0 0 0 0 S 0 0.0 0:00.00 fsnotify_mark
[Fri Aug 18 10:54:29.625 2017] 505 root 0 -20 0 0 0 S 0 0.0 0:00.00 nfsiod
[Fri Aug 18 10:54:29.625 2017] 515 root 0 -20 0 0 0 S 0 0.0 0:00.00 crypto
[Fri Aug 18 10:54:29.625 2017] 602 root 20 0 0 0 0 S 0 0.0 28:36.10 kworker/0:2
[Fri Aug 18 10:54:29.625 2017] 603 root 20 0 0 0 0 S 0 0.0 0:00.00 kworker/u4:1
[Fri Aug 18 10:54:29.641 2017] 1129 root 20 0 2440 1232 852 S 0 0.1 0:00.20 dropbear
[Fri Aug 18 10:54:29.641 2017] 1147 root -51 0 0 0 0 S 0 0.0 0:00.00 irq/324-2100040
[Fri Aug 18 10:54:29.641 2017] 1148 root 0 -20 0 0 0 S 0 0.0 0:00.00 21000400.spi
[Fri Aug 18 10:54:29.641 2017] 1165 root -51 0 0 0 0 S 0 0.0 0:00.00 irq/328-2100060
[Fri Aug 18 10:54:29.641 2017] 1166 root 0 -20 0 0 0 S 0 0.0 0:00.00 21000600.spi
[Fri Aug 18 10:54:29.641 2017] 1186 root -51 0 0 0 0 S 0 0.0 0:00.00 irq/332-2100080
[Fri Aug 18 10:54:29.656 2017] 1187 root 0 -20 0 0 0 S 0 0.0 0:00.00 21000800.spi
[Fri Aug 18 10:54:29.656 2017] 1250 root 0 -20 0 0 0 S 0 0.0 0:00.00 kpsmoused
[Fri Aug 18 10:54:29.656 2017] 1266 root 20 0 2616 1540 1204 S 0 0.1 0:00.01 sh
[Fri Aug 18 10:54:29.656 2017] 1301 root 0 -20 0 0 0 S 0 0.0 0:00.00 deferwq
[Fri Aug 18 10:54:29.656 2017] 1308 root 20 0 0 0 0 S 0 0.0 0:06.07 ubi_bgt0d
[Fri Aug 18 10:54:29.672 2017] 1311 root 20 0 0 0 0 S 0 0.0 0:00.35 ubifs_bgt0_0
[Fri Aug 18 10:54:29.672 2017] 1317 root 20 0 1576 528 428 S 0 0.1 1:47.47 l2_meas_cons
[Fri Aug 18 10:54:29.672 2017] 1335 root 20 0 2672 1348 768 S 0 0.1 0:00.29 udevd
[Fri Aug 18 10:54:29.672 2017] 1493 root 20 0 2488 856 448 S 0 0.1 0:00.01 udevd
[Fri Aug 18 10:54:29.672 2017] 1494 root 20 0 2608 968 440 S 0 0.1 0:00.00 udevd
[Fri Aug 18 10:54:29.672 2017] 1595 root 20 0 0 0 0 S 0 0.0 0:00.00 kworker/1:0
[Fri Aug 18 10:54:29.687 2017] 1753 messageb 20 0 2300 320 168 S 0 0.0 0:00.00 dbus-daemon
[Fri Aug 18 10:54:29.687 2017] 1758 root 20 0 2012 492 396 S 0 0.0 0:00.00 dropbear
[Fri Aug 18 10:54:29.687 2017] 1762 root 20 0 11748 856 632 S 0 0.1 0:02.39 mpmsrv
[Fri Aug 18 10:54:29.687 2017] 1767 root 20 0 4472 956 712 S 0 0.1 0:00.00 softhsm-daemon
[Fri Aug 18 10:54:29.687 2017] 1780 root 20 0 1496 248 160 S 0 0.0 0:00.00 lad_tci6630
[Fri Aug 18 10:54:29.687 2017] 1787 root 20 0 6144 2636 2056 S 0 0.3 497:23.67 syslog-ng
[Fri Aug 18 10:54:29.703 2017] 1795 root 20 0 1848 872 468 S 0 0.1 3:51.26 afe0_server
[Fri Aug 18 10:54:29.703 2017] 1797 root 20 0 1848 664 424 S 0 0.1 0:00.04 afe1_server
[Fri Aug 18 10:54:29.703 2017] 1807 root 20 0 3792 968 740 S 0 0.1 0:00.02 vsftpd
[Fri Aug 18 10:54:29.703 2017] 1840 root 20 0 0 0 0 S 0 0.0 0:00.01 ubi_bgt7d
[Fri Aug 18 10:54:29.703 2017] 1844 root 20 0 0 0 0 S 0 0.0 0:00.00 ubifs_bgt7_0
[Fri Aug 18 10:54:29.719 2017] 1847 root 20 0 0 0 0 S 0 0.0 0:03.30 ubi_bgt8d
[Fri Aug 18 10:54:29.719 2017] 1851 root 20 0 0 0 0 S 0 0.0 0:01.03 ubifs_bgt8_0
[Fri Aug 18 10:54:29.719 2017] 2034 root 20 0 3408 796 376 S 0 0.1 1:56.20 zebra
[Fri Aug 18 10:54:29.719 2017] 2051 root 20 0 18840 356 268 S 0 0.0 2:32.82 dropbear_ctrl
[Fri Aug 18 10:54:29.719 2017] 2098 root 20 0 31060 688 540 S 0 0.1 464:16.97 msgrouter.out
[Fri Aug 18 10:54:29.719 2017] 2143 root 20 0 2488 1388 948 S 0 0.1 19:22.66 spico_check_net
[Fri Aug 18 10:54:29.734 2017] 2156 root 20 0 2556 864 352 S 0 0.1 9:49.09 spico_chk_inact
[Fri Aug 18 10:54:29.734 2017] 2161 root 20 0 1932 672 548 S 0 0.1 2:25.01 lte_oamSDM
[Fri Aug 18 10:54:29.734 2017] 2182 root 23 3 39048 16m 3384 S 0 1.6 29:52.74 lte_oam
[Fri Aug 18 10:54:29.734 2017] 2209 root 20 0 1568 488 412 S 0 0.0 0:00.01 getty
[Fri Aug 18 10:54:29.734 2017] 2214 root -2 0 1364 1328 1012 S 0 0.1 1:20.19 watchdog
[Fri Aug 18 10:54:29.750 2017] 2220 root 20 0 1660 828 636 S 0 0.1 13:22.13 oam_transport_T
[Fri Aug 18 10:54:29.750 2017] 2222 root 20 0 20532 13m 1176 S 0 1.3 14:12.31 lte_tr069
[Fri Aug 18 10:54:29.750 2017] 2227 root 20 0 2364 696 588 S 0 0.1 0:35.27 crond
[Fri Aug 18 10:54:29.750 2017] 2278 root 20 0 1968 660 480 S 0 0.1 0:00.00 starter
[Fri Aug 18 10:54:29.750 2017] 2281 root 20 0 136m 2772 1944 S 0 0.3 9:51.47 charon
[Fri Aug 18 10:54:29.750 2017] 2357 root 20 0 28308 756 608 S 0 0.1 50:47.63 central_process
[Fri Aug 18 10:54:29.765 2017] 2359 root 20 0 1656 804 648 S 0 0.1 7:17.41 oam_radio
[Fri Aug 18 10:54:29.765 2017] 2360 root 20 0 1684 880 692 S 0 0.1 217:14.04 oam_system
[Fri Aug 18 10:54:29.765 2017] 2361 root 20 0 18332 10m 1656 S 0 1.1 11:12.48 lte_son_TDD
[Fri Aug 18 10:54:29.765 2017] 2362 root 20 0 43672 30m 3420 S 0 3.0 13:05.53 lte_rrm_TDD
[Fri Aug 18 10:54:29.765 2017] 2363 root 20 0 46368 12m 5276 S 0 1.3 1218:39 lte_rrc_TDD
[Fri Aug 18 10:54:29.765 2017] 2380 root 20 0 72480 2680 956 S 0 0.3 0:03.23 rfsdk_svc
[Fri Aug 18 10:54:29.781 2017] 2654 root 20 0 1316 228 184 S 0 0.0 0:00.00 sleep
[Fri Aug 18 10:54:29.781 2017] 2753 root 20 0 1316 228 184 S 0 0.0 0:00.00 sleep
[Fri Aug 18 10:54:29.781 2017] 2836 root 20 0 0 0 0 S 0 0.0 2:25.52 kworker/u4:3
[Fri Aug 18 10:54:29.781 2017] 2865 root 20 0 5040 1364 836 S 0 0.1 161:24.40 netfpproxy.out
[Fri Aug 18 10:54:29.781 2017] 2885 root 20 0 2220 964 744 R 0 0.1 0:00.01 top
[Fri Aug 18 10:54:29.781 2017] 2887 root 20 0 1296 388 332 S 0 0.0 0:15.92 log_rotate
[Fri Aug 18 10:54:29.781 2017] 2889 root 20 0 10836 680 560 S 0 0.1 4:01.94 phy_meas_svc
[Fri Aug 18 10:54:29.781 2017] 2891 root 20 0 1888 672 552 S 0 0.1 16:01.00 l2_log_stat_con
[Fri Aug 18 10:54:29.781 2017] 2893 root 20 0 1660 644 536 S 0 0.1 11:27.49 l2_consumer
[Fri Aug 18 10:54:29.781 2017] 3214 root 20 0 0 0 0 S 0 0.0 0:00.00 kworker/0:0

===

On the attached log file, you can find out that Cpu1 usage is higher than 70% always, but cannot find out high load tasks.

How can I understand ?

Is there any other checking point to clarify the high load?

Thanks,

Shinha

0842.NP4000282_top.log

over 8 years ago

0 Yordan Kovachev over 8 years ago

TI__Guru**** 161600 points

Hi,

Which SDK is this?
Is this a custom board or TI EVM? If this is a TI EVM, can you try switching to newer sdk (kernel 4.9) and check the output of top?

Best Regards,
Yordan

0 Shinha over 8 years ago in reply to Yordan Kovachev

Expert 1660 points

Yordan,
Thanks for your reply.

We are using MCSDK 3.1.4.7 (kernel 3.10.10).
Actually it happened on our board not TI EVM.
And it did not happened on all board, just several board. (with the same Kernel and Applications)

What we wan to know is why shown top report high usage regardless of not showing high load tasks.
How can we figure out the result? (you have any idea?)

Thanks,
Shinha.

0 Yordan Kovachev over 8 years ago in reply to Shinha

TI__Guru**** 161600 points

Let me do some research and I will update the thread.

Can you try with ps aux? Do you get the same results?

Best Regards,
Yordan

0 Shinha over 8 years ago in reply to Yordan Kovachev

Expert 1660 points

Yordan,

We had the result of "ps -elfL" instead of "ps -ax".
I cannot clarify the result, could you check the below log?
Some commands (eg get_spico_log.sh and real_log_collect.sh) are not exerted on normal operation, just for gather some logs.

++++++++++++++++++++++++++++++
Running: ps -elfL
++++++++++++++++++++++++++++++
F S UID PID PPID LWP C NLWP PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
4 S root 1 0 1 0 1 80 0 - 330 poll_s 14:47 ? 00:00:02 init [5]
1 S root 2 0 2 0 1 80 0 - 0 kthrea 14:47 ? 00:00:00 [kthreadd]
1 S root 3 2 3 0 1 80 0 - 0 smpboo 14:47 ? 00:00:01 [ksoftirqd/0]
1 S root 4 2 4 0 1 80 0 - 0 worker 14:47 ? 00:00:00 [kworker/0:0]
1 S root 5 2 5 0 1 60 -20 - 0 worker 14:47 ? 00:00:00 [kworker/0:0H]
1 S root 7 2 7 0 1 -40 - - 0 smpboo 14:47 ? 00:00:00 [migration/0]
1 S root 8 2 8 0 1 80 0 - 0 rcu_gp 14:47 ? 00:00:00 [rcu_bh]
1 S root 9 2 9 0 1 80 0 - 0 rcu_gp 14:47 ? 00:00:00 [rcu_sched]
1 S root 10 2 10 0 1 -40 - - 0 smpboo 14:47 ? 00:00:00 [migration/1]
1 S root 11 2 11 0 1 80 0 - 0 smpboo 14:47 ? 00:00:00 [ksoftirqd/1]
1 S root 13 2 13 0 1 60 -20 - 0 worker 14:47 ? 00:00:00 [kworker/1:0H]
1 S root 14 2 14 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [khelper]
5 S root 15 2 15 0 1 80 0 - 0 devtmp 14:47 ? 00:00:00 [kdevtmpfs]
1 S root 19 2 19 0 1 80 0 - 0 worker 14:47 ? 00:00:01 [kworker/0:1]
1 S root 20 2 20 0 1 80 0 - 0 worker 14:47 ? 00:00:00 [kworker/1:1]
1 S root 240 2 240 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [writeback]
1 S root 242 2 242 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [bioset]
1 S root 244 2 244 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [kblockd]
1 S root 251 2 251 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [ata_sff]
1 S root 261 2 261 0 1 80 0 - 0 hub_th 14:47 ? 00:00:00 [khubd]
4 Z root 329 2232 329 1 1 80 0 - 0 exit 15:15 ? 00:00:00 [logrotate] <defunct>
0 S root 335 2794 335 0 1 80 0 - 569 wait 15:15 pts/1 00:00:00 /bin/sh /spico_mgmt/get_spico_log.sh
0 S root 363 335 363 0 1 99 19 - 606 wait 15:15 pts/1 00:00:00 /bin/sh /spico_mgmt/real_log_collect.sh -l spico_supportlog_k2l-evm_c0a83d94_20170821151502 -t /var/tmp/spico_supportlog_k2l-evm_c0a83d94_20170821151502_335 -d 3 -c
0 S root 364 335 364 0 1 80 0 - 329 hrtime 15:15 pts/1 00:00:00 sleep 3
0 R root 379 363 379 0 1 99 19 - 551 - 15:15 pts/1 00:00:00 ps -elfL
1 S root 424 2 424 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [rpciod]
1 S root 436 2 436 0 1 80 0 - 0 kswapd 14:47 ? 00:00:00 [kswapd0]
1 S root 491 2 491 0 1 80 0 - 0 fsnoti 14:47 ? 00:00:00 [fsnotify_mark]
1 S root 505 2 505 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [nfsiod]
1 S root 515 2 515 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [crypto]
4 S root 957 1 957 0 1 80 0 - 394 hrtime 14:51 ? 00:00:00 ./../tools/l2_meas_cons
5 S root 1147 2 1147 0 1 9 - - 0 irq_th 14:47 ? 00:00:00 [irq/324-2100040]
1 S root 1148 2 1148 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [21000400.spi]
5 S root 1165 2 1165 0 1 9 - - 0 irq_th 14:47 ? 00:00:00 [irq/328-2100060]
1 S root 1166 2 1166 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [21000600.spi]
5 S root 1186 2 1186 0 1 9 - - 0 irq_th 14:47 ? 00:00:00 [irq/332-2100080]
1 S root 1187 2 1187 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [21000800.spi]
1 S root 1250 2 1250 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [kpsmoused]
1 S root 1301 2 1301 0 1 60 -20 - 0 rescue 14:47 ? 00:00:00 [deferwq]
1 S root 1308 2 1308 0 1 80 0 - 0 ubi_th 14:47 ? 00:00:00 [ubi_bgt0d]
1 S root 1311 2 1311 0 1 80 0 - 0 ubifs_ 14:47 ? 00:00:00 [ubifs_bgt0_0]
5 S root 1335 1 1335 0 1 80 0 - 653 SyS_ep 14:47 ? 00:00:00 /lib/udev/udevd -d
5 S root 1480 1335 1480 0 1 80 0 - 666 SyS_ep 14:47 ? 00:00:00 /lib/udev/udevd -d
5 S root 1484 1335 1484 0 1 80 0 - 666 SyS_ep 14:47 ? 00:00:00 /lib/udev/udevd -d
5 S 999 1742 1 1742 0 1 80 0 - 575 SyS_ep 14:47 ? 00:00:00 /usr/bin/dbus-daemon --system
1 S root 1747 1 1747 0 1 80 0 - 503 poll_s 14:47 ? 00:00:00 /usr/sbin/dropbear -r /etc/dropbear/dropbear_rsa_host_key -p 22 -B
5 S root 1751 1 1751 0 2 80 0 - 2937 poll_s 14:47 ? 00:00:02 /usr/bin/mpmsrv
1 S root 1751 1 1754 0 2 80 0 - 2937 poll_s 14:47 ? 00:00:00 /usr/bin/mpmsrv
1 S root 1756 1 1756 0 1 80 0 - 1118 poll_s 14:47 ? 00:00:00 /usr/bin/softhsm-daemon
5 S root 1769 1 1769 0 1 80 0 - 374 pipe_w 14:47 ? 00:00:00 /usr/bin/lad_tci6630 -l lad.txt
5 S root 1776 1 1776 0 1 80 0 - 1535 poll_s 14:47 ? 00:00:07 /usr/sbin/syslog-ng
5 S root 1779 1 1779 0 1 80 0 - 563 poll_s 14:47 ? 00:00:00 /usr/sbin/thttpd -d /srv/www -u root -c /cgi-bin/* -p 8080
1 S root 1784 1 1784 0 1 80 0 - 462 poll_s 14:47 ? 00:00:00 /usr/bin/afe0_server /var/run/rfsdk/afe0
1 S root 1786 1 1786 0 1 80 0 - 462 poll_s 14:47 ? 00:00:00 /usr/bin/afe1_server /var/run/rfsdk/afe1
4 S root 1796 1 1796 0 1 80 0 - 948 inet_c 14:47 ? 00:00:00 /usr/sbin/vsftpd
1 S root 1827 2 1827 0 1 80 0 - 0 ubi_th 14:47 ? 00:00:00 [ubi_bgt7d]
1 S root 1831 2 1831 0 1 80 0 - 0 ubifs_ 14:47 ? 00:00:00 [ubifs_bgt7_0]
1 S root 1834 2 1834 0 1 80 0 - 0 ubi_th 14:47 ? 00:00:00 [ubi_bgt8d]
1 S root 1838 2 1838 0 1 80 0 - 0 ubifs_ 14:47 ? 00:00:00 [ubifs_bgt8_0]
1 S root 1949 2 1949 0 1 80 0 - 0 worker 14:47 ? 00:00:00 [kworker/1:2]
1 S root 2035 1 2035 0 1 80 0 - 852 poll_s 14:48 ? 00:00:00 /usr/sbin/zebra -d -u root -g root
1 S root 2052 1 2052 0 3 80 0 - 4710 pause 14:48 ? 00:00:00 /usr/sbin/dropbear_ctrl -v 5
1 S root 2052 1 2053 0 3 80 0 - 4710 hrtime 14:48 ? 00:00:00 /usr/sbin/dropbear_ctrl -v 5
1 S root 2052 1 2054 0 3 80 0 - 4710 hrtime 14:48 ? 00:00:00 /usr/sbin/dropbear_ctrl -v 5
4 S root 2096 1 2096 0 4 80 0 - 7765 futex_ 14:48 ? 00:00:00 /usr/bin/msgrouter.out -d 10 -c 15 -v
1 S root 2096 1 2101 0 4 80 0 - 7765 skb_re 14:48 ? 00:00:00 /usr/bin/msgrouter.out -d 10 -c 15 -v
1 S root 2096 1 2102 0 4 80 0 - 7765 skb_re 14:48 ? 00:00:00 /usr/bin/msgrouter.out -d 10 -c 15 -v
1 S root 2096 1 2103 0 4 80 0 - 7765 futex_ 14:48 ? 00:00:08 /usr/bin/msgrouter.out -d 10 -c 15 -v
0 S root 2141 1 2141 0 1 80 0 - 560 wait 14:48 ? 00:00:00 /bin/sh /spico_mgmt/spico_check_netdev.sh
0 S root 2143 1 2143 0 1 80 0 - 557 wait 14:48 ? 00:00:00 /bin/sh /spico_mgmt/spico_check_inner.sh
0 S root 2152 2143 2152 0 1 80 0 - 329 hrtime 14:48 ? 00:00:00 sleep 2400
0 S root 2155 1 2155 0 1 80 0 - 483 poll_s 14:48 ? 00:00:00 ./lte_oamSDM ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
4 S root 2175 2155 2175 0 6 83 3 - 9154 poll_s 14:48 ? 00:00:00 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
1 S root 2175 2155 2220 0 6 80 0 - 9154 futex_ 14:48 ? 00:00:00 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
5 S root 2175 2155 2221 0 6 80 0 - 9154 futex_ 14:48 ? 00:00:02 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
1 S root 2175 2155 2222 0 6 80 0 - 9154 futex_ 14:48 ? 00:00:00 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
1 S root 2175 2155 2223 0 6 80 0 - 9154 futex_ 14:48 ? 00:00:00 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
1 S root 2175 2155 2224 0 6 80 0 - 9154 futex_ 14:48 ? 00:00:00 lte_oam ../cfg/Proprietary_eNodeB_Data_Model.xml ../cfg/eNodeB_Data_Model_TR_196_based.xml
0 S root 2198 2175 2198 0 1 80 0 - 419 poll_s 14:48 ? 00:00:00 oam_transport_TDD
0 S root 2199 2175 2199 0 2 80 0 - 2829 hrtime 14:48 ? 00:00:00 lte_tr069
1 S root 2199 2175 2274 0 2 80 0 - 2829 inet_c 14:49 ? 00:00:00 lte_tr069
0 S root 2204 1 2204 0 1 80 0 - 392 n_tty_ 14:48 ttyS0 00:00:00 /sbin/getty 115200 ttyS0
5 S root 2212 1 2212 0 1 58 - - 341 hrtime 14:48 ? 00:00:00 /usr/sbin/watchdog
1 S root 2232 1 2232 0 1 80 0 - 591 hrtime 14:48 ? 00:00:00 /usr/sbin/crond -l 0 -L /var/log/cron.log
1 S root 2251 1 2251 0 1 80 0 - 509 poll_s 14:49 ? 00:00:00 /usr/libexec/ipsec/starter --daemon charon
4 S root 2252 2251 2252 0 17 80 0 - 34976 sigtim 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2253 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2254 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2255 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2256 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2257 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2258 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2259 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2260 0 17 80 0 - 34976 poll_s 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2261 0 17 80 0 - 34976 poll_s 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2262 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2263 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
5 S root 2252 2251 2264 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2265 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2266 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2252 2251 2267 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
5 S root 2252 2251 2268 0 17 80 0 - 34976 futex_ 14:49 ? 00:00:00 /usr/libexec/ipsec/charon --use-syslog --debug-ike 2 --debug-knl 3 --debug-cfg 0
1 S root 2269 1747 2269 0 1 80 0 - 610 poll_s 14:49 ? 00:00:01 /usr/sbin/dropbear -r /etc/dropbear/dropbear_rsa_host_key -p 22 -B
4 S root 2270 2269 2270 0 1 80 0 - 654 wait 14:49 pts/0 00:00:00 -sh
0 S root 2271 2270 2271 0 1 80 0 - 656 n_tty_ 14:49 pts/0 00:00:00 bash
0 S root 2291 2175 2291 0 3 80 0 - 7077 poll_s 14:49 ? 00:00:00 central_process_TDD
1 S root 2291 2175 2301 0 3 80 0 - 7077 skb_re 14:49 ? 00:00:00 central_process_TDD
1 S root 2291 2175 2422 0 3 80 0 - 7077 poll_s 14:49 ? 00:00:00 central_process_TDD
0 S root 2293 2175 2293 0 1 80 0 - 419 poll_s 14:49 ? 00:00:00 oam_radio
0 S root 2294 2175 2294 0 1 80 0 - 461 poll_s 14:49 ? 00:00:03 oam_system 0
0 S root 2295 2175 2295 0 1 80 0 - 4871 poll_s 14:49 ? 00:00:00 lte_son_TDD ../cfg/eNodeB_Configuration.cfg 1
0 S root 2296 2175 2296 0 1 80 0 - 9886 poll_s 14:49 ? 00:00:02 lte_rrm_TDD 1 ../cfg/eNodeB_Configuration.cfg
4 S root 2297 2175 2297 0 3 80 0 - 10940 poll_s 14:49 ? 00:00:04 lte_rrc_TDD ../cfg/eNodeB_Configuration.cfg
1 S root 2297 2175 2305 0 3 80 0 - 10940 futex_ 14:49 ? 00:00:03 lte_rrc_TDD ../cfg/eNodeB_Configuration.cfg
1 S root 2297 2175 2306 0 3 -27 - - 10940 futex_ 14:49 ? 00:00:00 lte_rrc_TDD ../cfg/eNodeB_Configuration.cfg
0 S root 2311 1 2311 0 4 80 0 - 18120 pause 14:49 ? 00:00:00 /usr/bin/rfsdk_svc
5 S root 2311 1 2314 0 4 80 0 - 18120 SyS_ep 14:49 ? 00:00:00 /usr/bin/rfsdk_svc
1 S root 2311 1 2330 0 4 80 0 - 18120 poll_s 14:49 ? 00:00:04 /usr/bin/rfsdk_svc
1 S root 2311 1 2331 0 4 80 0 - 18120 skb_re 14:49 ? 00:00:00 /usr/bin/rfsdk_svc
1 S root 2421 2 2421 0 1 80 0 - 0 worker 14:49 ? 00:00:00 [kworker/u4:2]
5 S root 2424 1 2424 0 3 80 0 - 1260 futex_ 14:49 ? 00:00:00 /usr/bin/netfpproxy.out -p /usr/lib/netfp_proxy/plugins/netfpproxy_plugin.so -d 10
1 S root 2424 1 2425 0 3 80 0 - 1260 skb_re 14:49 ? 00:00:00 /usr/bin/netfpproxy.out -p /usr/lib/netfp_proxy/plugins/netfpproxy_plugin.so -d 10
1 S root 2424 1 2426 0 3 80 0 - 1260 poll_s 14:49 ? 00:00:02 /usr/bin/netfpproxy.out -p /usr/lib/netfp_proxy/plugins/netfpproxy_plugin.so -d 10
0 S root 2470 1 2470 0 1 80 0 - 324 hrtime 14:49 ? 00:00:00 ./../tools/log_rotate
4 S root 2472 1 2472 0 2 80 0 - 2709 hrtime 14:49 ? 00:00:00 ./../tools/phy_meas_svc
1 S root 2472 1 2477 0 2 80 0 - 2709 poll_s 14:49 ? 00:00:00 ./../tools/phy_meas_svc
4 S root 2474 1 2474 0 1 80 0 - 472 hrtime 14:49 ? 00:00:00 ./../tools/l2_log_stat_cons
4 S root 2476 1 2476 0 1 80 0 - 415 hrtime 14:49 ? 00:00:00 ./../tools/l2_consumer
1 S root 2670 1747 2670 0 1 80 0 - 610 poll_s 15:13 ? 00:00:00 /usr/sbin/dropbear -r /etc/dropbear/dropbear_rsa_host_key -p 22 -B
4 S root 2677 2670 2677 0 1 80 0 - 660 wait 15:13 pts/1 00:00:00 -sh
0 S root 2794 2677 2794 0 1 80 0 - 661 wait 15:13 pts/1 00:00:00 bash
1 S root 3954 2 3954 0 1 80 0 - 0 worker 14:53 ? 00:00:00 [kworker/u4:3]
0 S root 4051 2141 4051 0 1 80 0 - 329 hrtime 15:14 ? 00:00:00 sleep 10

One things;
Do you know how get the frequency to calculate the usage for each Cores?
On the normal board, I had excuted "cat /proc/cpuinfo"
Only displayed "BogoMIPS : 399.36" fro Core0 and Core1.

Thanks,
Shinha.

0 Shinha over 8 years ago in reply to Shinha

Expert 1660 points

Yordan,

I had check the related issue on E2E and then find the similar issue;

e2e.ti.com/.../433791

Is it the same issue with ours?

From our customer, I heard that our board could be recorded by reboot and it happened randomly.
If happened once, It did not recovered till restarting.

Thanks,
Shinha

0 Shinha over 8 years ago in reply to Shinha

Expert 1660 points

Yordan and TI experts,

Any one can explain the unusual behavior?

Only recored by restarting. we have to explain to our customers.

Thanks,

Shinha.

0 Yordan Kovachev over 8 years ago in reply to Shinha

TI__Guru**** 161600 points

Hi,

Nothing unusual in the ps output.

What bothers me is the following:

We are using MCSDK 3.1.4.7 (kernel 3.10.10).
Actually it happened on our board not TI EVM.
And it did not happened on all board, just several board. (with the same Kernel and Applications)

Are all custom boards the same? Is there a way to verify if this is not somehow a manufacturing error, for example:
wrong layout of the power rails, unreliable soldering, etc...

The e2e thread you refer uses an older kernel & the problem was reproducible on the TI EVM, when here you say you cannot reproduce it on TI EVM, also there has been quite a lot of kernel updates (latest SDKs use kernel 4.9), so I doubt that you're experiencing the same problem.

Best Regards,
Yordan

0 Rex Chang over 8 years ago in reply to Yordan Kovachev

TI__Guru 50170 points

Shinha,

The similiar issue in the link you provided was on MCSDK 3.1.1, and the core got locked up when the test application running a 10ms timer infinitely. We tried the same application on MCSDK 3.1.4. We did see one of the core idle time got dropped to 0%, but could not reproduce the lock up

Is one of your application has short timer? The above mentioned not being able to lock up but low idle % in MCSDK 3.1.4 was not observed when using RT Linux. Nor in any of the processor SDK releases.

I did a search on internet, and not sure if the link can hlep to point to the process hogging CPU, unix.stackexchange.com/.../how-to-find-which-process-is-causing-high-cpu-usage

Rex

0 Shinha over 8 years ago in reply to Rex Chang

Expert 1660 points

Yordan & Rex,

Sorry for wrong information for our environment.

-. We are using MCSDK3.1.2.5 (Kernel 3.10.10). not MCSDK3.1.4.7

-. Also It als really happened randomly, It happened very rarely and disappear after reboot command executed.

So It is hard to reproduce in our lab environment. We got the information on our commercial environment.

Thanks,

Shinha.

0 Shinha over 8 years ago in reply to Shinha

Expert 1660 points

Yordan & Rex,

I had tried "e2e.ti.com/.../433791, and then it was reproduced on our board.

Could you have any guid to fix this issue on our current Kernel version ?

Thanks,
Shinha.

0 Rex Chang over 8 years ago in reply to Shinha

TI__Guru 50170 points

Hi, Shinha,

I couldn't root cause the issue, but noticed the behavior does not show up in newer version. Because the kernel version is different, we can't pin point what made the symptom disappeared. My suggestion is to try if the issue does not appear in your lab using ProcSDK, and move to the newer kernel.

Rex

Processors

Processors forum

Linux/TCI6630K2L: Incomprehensible CPU usage reporting