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

Summary: aarch64 hikey ftrace function_graph cause soft lockup
Product: [Fedora] Fedora Reporter: Zamir SUN <sztsian>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: airlied, bskeggs, ewk, hdegoede, ichavero, itamar, jarodwilson, jglisse, john.j5live, jonathan, josef, kernel-maint, linville, mchehab, mjg59, pbrobinson, pwhalen, steved
Target Milestone: ---   
Target Release: ---   
Hardware: aarch64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-10-16 10:06:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 245418    

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.