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 1619081 - armhfp raspberry pi 2 ftrace function_graph cause soft lockup
Summary: armhfp raspberry pi 2 ftrace function_graph cause soft lockup
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: rawhide
Hardware: armv7hl
OS: Unspecified
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-20 03:09 UTC by Zamir SUN
Modified: 2019-10-19 13:50 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-19 13:50:46 UTC
Type: Bug
Embargoed:

Attachments (Terms of Use)

Description Zamir SUN 2018-08-20 03:09:26 UTC 
Description of problem:
ftrace function_graph cause soft lockup on raspberry pi 2.

Version-Release number of selected component (if applicable):
Raspberry Pi 2
4.18.0-1.fc29.armv7hl

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:
Soft lockup happens like

[  548.007970] hrtimer: interrupt took 1233022 ns                             
[  558.041846] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  568.800716] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  579.033833] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  584.007064] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [ksoftirqd/0:9]          
[  584.016131] Modules linked in: nf_tables_set nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nfk
[  584.111034]  dwc2 udc_core pwm_bcm2835 bcm2835 i2c_bcm2835 bcm2835_dma phy_generic     
[  584.121527] CPU: 0 PID: 9 Comm: ksoftirqd/0 Not tainted 4.18.0-1.fc29.armv7hl #1       
[  584.130868] Hardware name: BCM2835                                                     
[  584.135496] PC is at return_to_handler+0x0/0x18                                        
[  584.141454] LR is at ipv6_skip_exthdr+0x3c/0x150                                       
[  584.147481] pc : [<c03126fc>]    lr : [<c0b291d8>]    psr: a00d0013                    
[  584.155472] sp : ef14f998  ip : c0b290dc  fp : ef14f9c4                                
[  584.162222] r10: d1af0a61  r9 : ef14f9ce  r8 : ef14f9cd                                
[  584.168965] r7 : ebbf3800  r6 : 00000006  r5 : 00000028  r4 : c303b6c0                 
[  584.177264] r3 : ffffffdb  r2 : ef14f9cd  r1 : 00000028  r0 : 00000000                 
[  584.185564] Flags: NzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none          
[  584.220993] Control: 10c5387d  Table: 2bb0806a  DAC: 00000051                          
[  584.255132] CPU: 0 PID: 9 Comm: ksoftirqd/0 Not tainted 4.18.0-1.fc29.armv7hl #1       
[  584.291119] Hardware name: BCM2835                                                     
[  584.322656] [<c0313f7c>] (unwind_backtrace) from [<c03126fc>] (return_to_handler+0x0/0)
[  604.122506] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  614.874327] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  625.626735] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  635.866492] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  644.007065] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [kworker/0:3:516]        
[  644.043039] Modules linked in: nf_tables_set nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nfk
[  644.403178]  dwc2 udc_core pwm_bcm2835 bcm2835 i2c_bcm2835 bcm2835_dma phy_generic     
[  644.440343] CPU: 0 PID: 516 Comm: kworker/0:3 Tainted: G             L    4.18.0-1.fc21
[  644.505763] Hardware name: BCM2835                                                     
[  644.537605] Workqueue: events check_carrier [smsc95xx]                                 
[  644.571270] PC is at trace_graph_return+0x98/0xa8                                      
[  644.604172] LR is at ring_buffer_unlock_commit+0x30/0xbc                               
[  644.637430] pc : [<c0433160>]    lr : [<c0420804>]    psr: 60090113                    
[  644.671619] sp : ea42b9d0  ip : 00000b40  fp : ea42b9e4                                
[  644.704424] r10: 00000000  r9 : 00000002  r8 : c1409600                                
[  644.737178] r7 : 00000000  r6 : ea63f700  r5 : 00090113  r4 : ef6ed940                 
[  644.771684] r3 : 00000000  r2 : 00000000  r1 : 00000000  r0 : 00000000                 
[  644.806184] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none          
[  644.841449] Control: 10c5387d  Table: 29e2c06a  DAC: 00000051                          
[  644.875073] CPU: 0 PID: 516 Comm: kworker/0:3 Tainted: G             L    4.18.0-1.fc21
[  644.939049] Hardware name: BCM2835                                                     
[  644.970742] Workqueue: events check_carrier [smsc95xx]                                 
[  645.004781] [<c0313f7c>] (unwind_backtrace) from [<c03126fc>] (return_to_handler+0x0/0)
[  646.118763] sdhost-bcm2835 3f202000.mmc: timeout waiting for hardware interrupt.       
[  648.144234] ------------[ cut here ]------------                                       
[  648.158526] WARNING: CPU: 1 PID: 231 at drivers/mmc/host/bcm2835.c:899 bcm2835_threade]
[  648.187549] Modules linked in: nf_tables_set nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nfk
[  648.355094]  dwc2 udc_core pwm_bcm2835 bcm2835 i2c_bcm2835 bcm2835_dma phy_generic     
[  648.372886] CPU: 1 PID: 231 Comm: irq/80-mmc0 Tainted: G             L    4.18.0-1.fc21
[  648.401640] Hardware name: BCM2835                                                     
[  648.414922] [<c0313f7c>] (unwind_backtrace) from [<c030dc64>] (show_stack+0x20/0x24)   
[  648.432893] [<c030dc64>] (show_stack) from [<c0b48b84>] (dump_stack+0x88/0xa8)         
[  648.450356] [<c0b48b84>] (dump_stack) from [<c0351858>] (__warn+0xe8/0x104)            
[  648.467554] [<c0351858>] (__warn) from [<c0351bcc>] (warn_slowpath_null+0x4c/0x58)     
[  648.485400] [<c0351bcc>] (warn_slowpath_null) from [<bf01ba6c>] (bcm2835_threaded_irq+)
[  648.515403] [<bf01ba6c>] (bcm2835_threaded_irq [bcm2835]) from [<c03b4174>] (irq_threa)
[  648.545111] [<c03b4174>] (irq_thread_fn) from [<c03b4454>] (irq_thread+0x148/0x1e8)    
[  648.563445] [<c03b4454>] (irq_thread) from [<c0371524>] (kthread+0x150/0x168)          
[  648.581072] [<c0371524>] (kthread) from [<c03010e8>] (ret_from_fork+0x14/0x2c)         
[  648.598656] Exception stack(0xc32f9fb0 to 0xc32f9ff8)                                  
[  648.613894] 9fa0:                                     00000000 00000000 00000000 000000
[  648.642249] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000
[  648.670728] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000                
[  648.688078] ---[ end trace a33fc983575c4a56 ]---                                       
[  648.702969] Unable to handle kernel NULL pointer dereference at virtual address 0000004
[  648.731471] pgd = 76bf4cd9                                                             
[  648.744207] [00000014] *pgd=00000000                                                   
[  648.757747] Internal error: Oops: 5 [#1] SMP ARM                                       
[  648.772000] Modules linked in: nf_tables_set nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nfk
[  648.942995]  dwc2 udc_core pwm_bcm2835 bcm2835 i2c_bcm2835 bcm2835_dma phy_generic     
[  648.961056] CPU: 0 PID: 516 Comm: kworker/0:3 Tainted: G        W    L    4.18.0-1.fc21
[  648.990217] Hardware name: BCM2835                                                     
[  649.003563] Workqueue: events bcm2835_dma_complete_work [bcm2835]                      
[  649.019660] PC is at bcm2835_finish_data+0x40/0xb0 [bcm2835]                           
[  649.035272] LR is at bcm2835_finish_data+0x34/0xb0 [bcm2835]                           
[  649.050704] pc : [<bf01b954>]    lr : [<bf01b948>]    psr: 60090013                    
[  649.066736] sp : ea42bec0  ip : c031c0e0  fp : ea42bedc                                
[  649.081584] r10: 00000000  r9 : ee70cb74  r8 : c342e7a8                                
[  649.096405] r7 : c0319720  r6 : ef314200  r5 : 00000000  r4 : ee70cb40                 
[  649.112477] r3 : f1061000  r2 : 0000040e  r1 : 00000000  r0 : ee70cb40                 
[  649.128355] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none          
[  649.144857] Control: 10c5387d  Table: 29e2c06a  DAC: 00000051                          
[  649.159928] Process kworker/0:3 (pid: 516, stack limit = 0x33492ff5)                   
[  649.175539] Stack: (0xea42bec0 to 0xea42c000)                                          
[  649.188933] bec0: ee70cb70 ee70cb44 ee70cb40 c0319720 ea42bf0c ea42bee0 bf01bce0 bf01b0
[  649.215718] bee0: 00000000 00000000 c1411968 eaad7900 ee70cb70 ef6ea8c0 ef6edb00 000000
[  649.243184] bf00: ea42bf44 ea42bf10 c036b670 bf01bbe4 0000008a e889bc52 00000096 eaad70
[  649.270822] bf20: ef6ea8c0 ef6ea8c0 c1303d00 ef6ea8d8 eaad7914 00000008 ea42bf74 ea42b8
[  649.298568] bf40: c036c43c c036b434 00000000 ea987d80 eaae0e40 ea42a000 eaad7900 c036c8
[  649.326502] bf60: 00000000 ef147e98 ea42bfac ea42bf78 c0371524 c036c184 ea987d9c ea987c
[  649.354624] bf80: ea42bfac eaae0e40 c03713d4 00000000 00000000 00000000 00000000 000000
[  649.382830] bfa0: 00000000 ea42bfb0 c03010e8 c03713e0 00000000 00000000 00000000 000000
[  649.411234] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000
[  649.440207] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 000000
[  649.469948] [<bf01b954>] (bcm2835_finish_data [bcm2835]) from [<bf01bce0>] (bcm2835_dm)
[  649.503479] [<bf01bce0>] (bcm2835_dma_complete_work [bcm2835]) from [<c036b670>] (proc)
[  649.536238] [<c036b670>] (process_one_work) from [<c036c43c>] (worker_thread+0x2c4/0x4)
[  649.567460] [<c036c43c>] (worker_thread) from [<c0371524>] (kthread+0x150/0x168)       
[  649.586620] [<c0371524>] (kthread) from [<c03010e8>] (ret_from_fork+0x14/0x2c)         
[  649.605566] Exception stack(0xea42bfb0 to 0xea42bff8)                                  
[  649.622241] bfa0:                                     00000000 00000000 00000000 000000
[  649.653339] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 000000
[  649.684431] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000                
[  649.702625] Code: eb4c01e0 e59420a4 e5943018 e5832038 (e5953014)                       
[  649.720703] ---[ end trace a33fc983575c4a57 ]---                                       



Expected results:
Ftrace function_graph tracer should work fine

Additional info:
Comment 1 Peter Robinson 2019-10-13 17:52:19 UTC 
Does this still happen with 5.3 kernels?
Comment 2 Zamir SUN 2019-10-16 10:09:02 UTC 
Currently, I cannot test on my RPI2. I'll follow-up as soon as I can do a test there.
Comment 3 Zamir SUN 2019-10-19 13:50:46 UTC 
Well, function_graph tracer is disabled on RPI2 kernel, which means this is no longer reproducible.

[root@rpi2 tracing]# uname -r
5.3.2-300.fc30.armv7hl
[root@rpi2 tracing]# cat /sys/kernel/debug/tracing/available_tracers 
hwlat blk wakeup_dl wakeup_rt wakeup function nop

I'll close as insufficient data in case function_graph tracer is enabled again later.
Note You need to log in before you can comment on or make changes to this bug.