Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1616193 - aarch64 hikey ftrace function_graph cause soft lockup
Summary: aarch64 hikey ftrace function_graph cause soft lockup
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: rawhide
Hardware: aarch64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: ARMTracker
TreeView+ depends on / blocked
 
Reported: 2018-08-15 08:44 UTC by Zamir SUN
Modified: 2019-10-16 10:06 UTC (History)
18 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-10-16 10:06:36 UTC
Type: Bug
Embargoed:

Attachments (Terms of Use)

Description Zamir SUN 2018-08-15 08:44:13 UTC 
Description of problem:
ftrace function_graph cause soft lockup

Version-Release number of selected component (if applicable):
4.18.0-1.fc29.aarch64
96boards hikey (aka Hikey 620)

How reproducible:
Always

Steps to Reproduce:
1. cd /sys/kernel/debug/tracing/
2. echo function_graph > current_tracer
3. echo 1 > tracing_on

Actual results:

[ 2192.048976] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [kworker/0:1:13093]
[ 2192.059999] Modules linked in: ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ir
[ 2192.182233]  dw_drm_dsi snd soundcore cpufreq_dt uas usb_storage adv7511 drm_kms_helpe]
[ 2192.226217] CPU: 0 PID: 13093 Comm: kworker/0:1 Tainted: G            E     4.18.0-1.f1
[ 2192.239385] Hardware name: LeMaker 96Boards LeMaker HiKey/96Boards LeMaker HiKey, BIOS8
[ 2192.253575] Workqueue:            (null) (events_power_efficient)
[ 2192.263410] pstate: 80400005 (Nzcv daif +PAN -UAO) 
[ 2192.270825] pc : __do_softirq+0x98/0x300 
[ 2192.277061] lr : __do_softirq+0x64/0x300 
[ 2192.283220] sp : ffff000008003ed0
[ 2192.288574] x29: ffff000008003ed0 x28: ffff800070021d40
[ 2192.297354] x27: ffff000008a1d640 x26: ffff000008004000
[ 2192.306125] x25: ffff000008000000 x24: ffff800005f1f000
[ 2192.314896] x23: 0000000000000040 x22: ffff00000eb1bc10
[ 2192.323663] x21: 0000000000000000 x20: 0000000000000027
[ 2192.332423] x19: ffff800070021d40 x18: 000000000000001d
[ 2192.341186] x17: 0000000000000000 x16: 0000000000000000
[ 2192.349976] x15: 0000000000000001 x14: 0000000000000019
[ 2192.358750] x13: 0000000000000033 x12: 000000001c600000
[ 2192.367532] x11: ffff000008003b78 x10: 00000000000006d8
[ 2192.376302] x9 : ffff800005f0dc00 x8 : 0000000000000030
[ 2192.385072] x7 : ffff800005f09700 x6 : 00000000800e08c4
[ 2192.393852] x5 : 00000000ffffffff x4 : 0000000000000015
[ 2192.402628] x3 : 0000000000000000 x2 : 000000000000c8ce
[ 2192.411408] x1 : 000080006ec84000 x0 : ffff00000923b8c0
[ 2192.420207] Call trace:
[ 2192.424520]  __do_softirq+0x98/0x300 
[ 2192.430324]  irq_exit+0xc0/0xd0
[ 2192.435541]  __handle_domain_irq+0x70/0xc0 
[ 2192.441985]  gic_handle_irq+0x58/0xa8
[ 2192.447884]  el1_irq+0xe8/0x180
[ 2192.453094]  finish_task_switch+0x74/0x1f0 
[ 2192.459573]  __schedule+0x264/0x8b8
[ 2192.465239]  schedule+0x30/0x88
[ 2192.470451]  worker_thread+0xd0/0x400
[ 2192.476353]  kthread+0x130/0x138 
[ 2192.481664]  ret_from_fork+0x10/0x18 

Expected results:
function_graph should work as expected

Additional info:
Comment 1 Zamir SUN 2018-08-15 09:06:50 UTC 
FYI, this works fine on Raspberry Pi 3.

[root@rpi3 tracing]# uname -r
4.18.0-1.fc29.aarch64
[root@rpi3 kernel-aarch64]# cd /sys/kernel/debug/tracing/
[root@rpi3 tracing]# cat available_tracers 
hwlat blk function_graph wakeup_dl wakeup_rt wakeup function nop
[root@rpi3 tracing]# echo function_graph > current_tracer 
[root@rpi3 tracing]# 
[root@rpi3 tracing]# echo 1 > tracing_on
[root@rpi3 tracing]# 
[root@rpi3 tracing]# cat trace | tail
 1) + 44.219 us   |                  }
 2)   9.323 us    |              }
 1) + 46.250 us   |                }
 0)   0.365 us    |                              dwc2_hcd_get_frame_number [dwc2]();
 2)   0.208 us    |              unlock_page();
 1)   0.365 us    |                _raw_spin_lock_irqsave();
 0)   0.156 us    |                              dwc2_hcd_select_transactions [dwc2]();
 2)               |              alloc_set_pte() {
 2)               |                add_mm_counter_fast() {
 0)   8.385 us    |                            }
Comment 2 Peter Robinson 2019-10-13 17:51:55 UTC 
Does this still happen with 5.3 kernels?
Comment 3 Zamir SUN 2019-10-16 10:06:36 UTC 
I just tested and confirm it works fine now

[root@hikey ~]# uname -r
5.3.2-300.fc30.aarch64
[root@hikey ~]# cd /sys/kernel/debug/tracing/
[root@hikey tracing]# echo function_graph > current_tracer
[root@hikey tracing]# echo 1 > tracing_on
[root@hikey tracing]# cat trace | tail
 7)   3.281 us    |                        pcpu_next_unpop();
 0)               |                  _cond_resched() {
 0)   3.229 us    |                    rcu_all_qs();
 7)   2.969 us    |                        mutex_unlock();
 0)   9.271 us    |                  }
 0)   3.177 us    |                  should_fail_alloc_page.isra.0();
 7) + 91.302 us   |                      }
 7) + 96.771 us   |                    }
 0)               |                  get_page_from_freelist() {
 0)               |                    rmqueue_pcplist.isra.0() {


No bug or warning message shows on console.

Closing as current release.
Note You need to log in before you can comment on or make changes to this bug.