This is the mail archive of the systemtap@sourceware.org mailing list for the systemtap project.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

[Bug runtime/18460] New: tracepoint_onthefly.exp kernel crash


https://sourceware.org/bugzilla/show_bug.cgi?id=18460

            Bug ID: 18460
           Summary: tracepoint_onthefly.exp kernel crash
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: runtime
          Assignee: systemtap at sourceware dot org
          Reporter: mcermak at redhat dot com
  Target Milestone: ---

With recent upstream bits I see tracepoint_onthefly.exp causing kernel crash on
ppc64(le/be) pretty reliably. E.g. using release-2.7-157-g35bd6e1548e9 (or in
beaker using older 22cabe6) on top of 3.10.0-229.el7.ppc64 I see:

=======
ibm-p730-06-lp2 login: [1645691.300056] INFO: rcu_sched detected stalls on
CPUs/tasks: { 0 2 3 4 5 6 7 8 9 10 11 12
[1645691.300159] Task dump for CPU 0:                                           
[1645691.300166] swapper/0       R  running task        0     0      0
0x00000000
[1645691.300180] Call Trace:                                                    
[1645691.300194] [c00000000130b840] [0005d8af9a1ddff2] 0x5d8af9a1ddff2
(unreliable)
[1645691.300208] [c00000000130ba10] [0000000022002082] 0x22002082               
[1645691.300218] Task dump for CPU 2:                                           
[1645691.300225] swapper/2       R  running task        0     0      1
0x00000804
[1645691.300238] Call Trace:                                                    
[1645691.300248] [c0000003f8d8f890] [c00000000048e63c] .find_next_bit+0x5c/0xf0
(unreliable)
[1645691.300261] [c0000003f8d8fa60] [0000000022000082] 0x22000082               
[1645691.300272] Task dump for CPU 3:                                           
[1645691.300278] swapper/3       R  running task        0     0      1
0x00000800
[1645691.300291] Call Trace:                                                    
[1645691.300298] [c0000003f8d93890] [c0000000004726e8]
.cpumask_next_and+0x28/0xa0 (unreliable)
[1645691.300313] [c0000003f8d93a60] [0000000022000082] 0x22000082               
[1645691.300322] Task dump for CPU 4:                                           
[1645691.300329] swapper/4       R  running task        0     0      1
0x00000800
[1645691.300342] Call Trace:                                                    
[1645691.300350] [c0000003f8d97890] [c000000000123d94]
.update_cfs_rq_blocked_load+0x34/0x160 (unreliable)
[1645691.300365] [c0000003f8d97a60] [0000000022000082] 0x22000082               
[1645691.300375] Task dump for CPU 5:                                           
[1645691.300381] swapper/5       R  running task        0     0      1
0x00000800
[1645691.300394] Call Trace:                                                    
[1645691.300402] [c0000003f8d9b890] [c0000000008eeb90] .__schedule+0x180/0xa50
(unreliable)
[1645691.300416] [c0000003f8d9ba60] [0000000022000082] 0x22000082               
[1645691.300426] Task dump for CPU 6:                                           
[1645691.300432] swapper/6       R  running task        0     0      1
0x00000800
[1645691.300445] Call Trace:                                                    
[1645691.300453] [c0000003f8d9f890] [c000000000123e84]
.update_cfs_rq_blocked_load+0x124/0x160 (unreliable)
[1645691.300468] [c0000003f8d9fa60] [0000000022000082] 0x22000082               
[1645691.300478] Task dump for CPU 7:                                           
[1645691.300484] swapper/7       R  running task        0     0      1
0x00000800
[1645691.300497] Call Trace:                                                    
[1645691.300504] [c0000003f8da3890] [c0000000008eeb90] .__schedule+0x180/0xa50
(unreliable)
[1645691.300518] [c0000003f8da3a60] [0000000022000082] 0x22000082               
[1645691.300527] Task dump for CPU 8:                                           
[1645691.300534] swapper/8       R  running task        0     0      1
0x00000800
[1645691.300546] Call Trace:                                                    
[1645691.300555] [c0000003f8da7890] [c00000000130ae00]
init_thread_union+0x2e00/0x4000 (unreliable)
[1645691.300569] [c0000003f8da7a60] [0000000022000082] 0x22000082               
[1645691.300579] Task dump for CPU 9:                                           
[1645691.300585] swapper/9       R  running task        0     0      1
0x00000800
[1645691.300598] Call Trace:                                                    
[1645691.300606] [c0000003f8dab890] [c0000000000698c8]
.memcpy_power7+0x128/0x7e0 (unreliable)
[1645691.300620] [c0000003f8daba60] [0000000022000082] 0x22000082               
[1645691.300630] Task dump for CPU 10:                                          
[1645691.300637] swapper/10      R  running task        0     0      1
0x00000800
[1645691.300649] Call Trace:                                                    
[1645691.300656] [c0000003f8daf890] [0005d8a88c18a8f0] 0x5d8a88c18a8f0
(unreliable)
[1645691.300669] [c0000003f8dafa60] [0000000022000082] 0x22000082               
[1645691.300679] Task dump for CPU 11:                                          
[1645691.300685] swapper/11      R  running task        0     0      1
0x00000800
[1645691.300698] Call Trace:                                                    
[1645691.300705] [c0000003f8db3890] [c0000000000684c4] .memset+0xd4/0xfc
(unreliable)
[1645691.300718] [c0000003f8db3a60] [0000000022000082] 0x22000082               
[1645691.300728] Task dump for CPU 12:                                          
[1645691.300734] swapper/12      R  running task        0     0      1
0x00000800
[1645691.300747] Call Trace:                                                    
[1645691.300754] [c0000003f8db7890] [c00000000013af60]
.cpuacct_charge+0x50/0x60 (unreliable)
[1645691.300768] [c0000003f8db7a60] [0000000022000082] 0x22000082               
[1645691.300778] Task dump for CPU 13:                                          
[1645691.300784] swapper/13      R  running task        0     0      1
0x00000800
[1645691.300797] Call Trace:                                                    
[1645691.300804] [c0000003f8dbb890] [c0000000008eeb54] .__schedule+0x144/0xa50
(unreliable)
[1645691.300818] [c0000003f8dbba60] [0000000022000082] 0x22000082               
[1645691.300828] Task dump for CPU 14:                                          
[1645691.300834] swapper/14      R  running task        0     0      1
0x00000800
[1645691.300846] Call Trace:                                                    
[1645691.300854] [c0000003f8dbf890] [c0000000008eeb90] .__schedule+0x180/0xa50
(unreliable)
[1645691.300867] [c0000003f8dbfa60] [0000000022000082] 0x22000082               
[1645691.300877] Task dump for CPU 15:                                          
[1645691.300883] swapper/15      R  running task        0     0      1
0x00000800
[1645691.300896] Call Trace:                                                    
[1645691.300903] [c0000003f8dc3890] [c00000000048e69c] .find_next_bit+0xbc/0xf0
(unreliable)
[1645691.300916] [c0000003f8dc3a60] [0000000022000082] 0x22000082               
[1645691.300926] Task dump for CPU 16:                                          
[1645691.300932] swapper/16      R  running task        0     0      1
0x00000800
[1645691.300945] Call Trace:                                                    
[1645691.300955] [c0000003f8dc7890] [c000000000129ba4] .update_curr+0xb4/0x2c0
(unreliable)
[1645691.300968] [c0000003f8dc7a60] [0000000022000082] 0x22000082
[1645691.300978] Task dump for CPU 17:                                          
[1645691.300984] swapper/17      R  running task        0     0      1
0x00000800
[1645691.300997] Call Trace:                                                    
[1645691.301004] [c0000003f8dcb890] [c00000000011b26c] .idle_cpu+0x5c/0x60
(unreliable)
[1645691.301017] [c0000003f8dcba60] [0000000022000082] 0x22000082               
[1645691.301027] Task dump for CPU 18:                                          
[1645691.301033] swapper/18      R  running task        0     0      1
0x00000800
[1645691.301046] Call Trace:                                                    
[1645691.301053] [c0000003f8dcf890] [c00000000012f0b0]
.find_busiest_group+0x560/0x980 (unreliable)
[1645691.301067] [c0000003f8dcfa60] [0000000022000082] 0x22000082               
[1645691.301077] Task dump for CPU 19:                                          
[1645691.301083] swapper/19      R  running task        0     0      1
0x00000800
[1645691.301096] Call Trace:                                                    
[1645691.301103] [c0000003f8dd3890] [c000000000114798]
.update_rq_clock+0x78/0x80 (unreliable)
[1645691.301117] [c0000003f8dd3a60] [0000000022000082] 0x22000082               
[1645691.301127] Task dump for CPU 20:                                          
[1645691.301133] swapper/20      R  running task        0     0      1
0x00000804
[1645691.301146] Call Trace:                                                    
[1645691.301153] [c0000003f8dd7890] [c0000000008f20d4]
._raw_spin_lock_irqsave+0x84/0x110 (unreliable)
[1645691.301168] [c0000003f8dd7a60] [0000000022000082] 0x22000082               
[1645691.301178] Task dump for CPU 22:                                          
[1645691.301184] stapio          R  running task        0 18042  27117
0x00008084
[1645691.301197] Call Trace:                                                    
[1645691.301203] [c000000344fff490] [0002855ba342a604] 0x2855ba342a604
(unreliable)
[1645691.301215] Task dump for CPU 23:                                          
[1645691.301221] swapper/23      R  running task        0     0      1
0x00000804
[1645691.301234] Call Trace:                                                    
[1645691.301241] [c0000003f8de3890] [c000000000129c88] .update_curr+0x198/0x2c0
(unreliable)
[1645691.301254] [c0000003f8de3a60] [0000000022000082] 0x22000082               
[1645691.301264] Task dump for CPU 24:                                          
[1645691.301270] swapper/24      R  running task        0     0      1
0x00000800
[1645691.301283] Call Trace:                                                    
[1645691.301290] [c0000003f8de7890] [c00000000012ea14]
.update_group_power+0x154/0x290 (unreliable)
[1645691.301305] [c0000003f8de7a60] [0000000022000082] 0x22000082               
[1645691.301314] Task dump for CPU 25:                                          
[1645691.301321] swapper/25      R  running task        0     0      1
0x00000800
[1645691.301333] Call Trace:                                                    
[1645691.301340] [c0000003f8deb890] [c0000000008eebc8] .__schedule+0x1b8/0xa50
(unreliable)
[1645691.301354] [c0000003f8deba60] [0000000022000082] 0x22000082               
[1645691.301363] Task dump for CPU 26:                                          
[1645691.301370] swapper/26      R  running task        0     0      1
0x00000800
[1645691.301382] Call Trace:                                                    
[1645691.301389] [c0000003f8def890] [c00000000012a6ec]
.dequeue_task_fair+0x35c/0xf30 (unreliable)
[1645691.301404] [c0000003f8defa60] [0000000022000082] 0x22000082               
[1645691.301414] Task dump for CPU 27:                                          
[1645691.301420] swapper/27      R  running task        0     0      1
0x00000800
[1645691.301432] Call Trace:                                                    
[1645691.301439] [c0000003f8df3890] [c00000000012ed44]
.find_busiest_group+0x1f4/0x980 (unreliable)
[1645691.301455] [c0000003f8df3a60] [0000000022000082] 0x22000082
=======

systemtap.log reads:

=======
Test Run By root on Thu May 28 03:21:55 2015
Native configuration is powerpc64-unknown-linux-gnu

                === systemtap tests === 

Schedule of variations:
    unix

Running target unix
Using /usr/share/dejagnu/baseboards/unix.exp as board description file for
target.
Using /usr/share/dejagnu/config/unix.exp as generic interface file for target.
Using ./config/unix.exp as tool-and-target-specific interface file.

Host: Linux ibm-p730-06-lp2.rhts.eng.bos.redhat.com 3.10.0-229.el7.ppc64 #1 SMP
Thu Jan 29 18:40:45 EST 2015 ppc64 ppc64 ppc64 GNU/Linux
Snapshot: version 2.8/0.160, commit release-2.7-157-g35bd6e1548e9 + changes
GCC: 4.8.3 [gcc (GCC) 4.8.3 20140911 (Red Hat 4.8.3-9)]
Distro: Red Hat Enterprise Linux Server release 7.1 (Maipo)
SElinux: Disabled


Running ./systemtap.onthefly/tracepoint_onthefly.exp ... 
Executing: kill -INT 17195
Executing: kill -KILL 17195
expected more patterns
got to pattern index -1, but there are 1 patterns
KFAIL: tracepoint_onthefly - otf_finish_at_start_disabled (invalid output)
(PRMS: 17256)
Executing: kill -INT 28628
Executing: kill -KILL 28628
PASS: tracepoint_onthefly - otf_finish_at_start_enabled (valid output)
Executing: kill -INT 4068
Executing: kill -KILL 4068
expected: * not registering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_disabled_iter_1 (invalid output) (PRMS:
17256)
Executing: kill -INT 12361
Executing: kill -KILL 12361
expected more patterns
got to pattern index 1, but there are 3 patterns
KFAIL: tracepoint_onthefly - otf_start_enabled_iter_1 (invalid output) (PRMS:
17256)
Executing: kill -INT 20984
Executing: kill -KILL 20984
expected: * not registering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_disabled_iter_2 (invalid output) (PRMS:
17256)
Executing: kill -INT 30046
Executing: kill -KILL 30046
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_enabled_iter_2 (invalid output) (PRMS:
17256)
Executing: kill -INT 6538
Executing: kill -KILL 6538
expected: * not registering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_disabled_iter_3 (invalid output) (PRMS:
17256)
Executing: kill -INT 16029
Executing: kill -KILL 16029
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_enabled_iter_3 (invalid output) (PRMS:
17256)
Executing: kill -INT 25734
Executing: kill -KILL 25734
expected: * not registering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_disabled_iter_4 (invalid output) (PRMS:
17256)
Executing: kill -INT 3446
Executing: kill -KILL 3446
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_enabled_iter_4 (invalid output) (PRMS:
17256)
Executing: kill -INT 13612
Executing: kill -KILL 13612
expected: * not registering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_disabled_iter_5 (invalid output) (PRMS:
17256)
Executing: kill -INT 24473
Executing: kill -KILL 24473
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_start_enabled_iter_5 (invalid output) (PRMS:
17256)
Executing: kill -INT 2772
Executing: kill -KILL 2772
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_timer_100ms (invalid output) (PRMS: 17256)
Executing: kill -INT 10607
Executing: kill -KILL 10607
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_timer_50ms (invalid output) (PRMS: 17256)
Executing: kill -INT 18132
Executing: kill -KILL 18132
kill: kill: sending signal to 18132 failed: No such process
expected: * unregistering (tracepoint) pidx ?
received: toggling
KFAIL: tracepoint_onthefly - otf_timer_10ms (invalid output) (PRMS: 17256)
Executing: kill -INT 23737
Executing: kill -KILL 23737
PASS: tracepoint_onthefly - otf_stress_5ms_iter_50 (survived)
Executing: kill -INT 30983
Executing: kill -KILL 30983
PASS: tracepoint_onthefly - otf_stress_1ms_iter_50 (survived)
Executing: kill -INT 5593
Executing: kill -KILL 5593
PASS: tracepoint_onthefly - otf_stress_500us_iter_50 (survived)
Executing: kill -INT 12659
Executing: kill -KILL 12659
PASS: tracepoint_onthefly - otf_stress_100us_iter_50 (survived)
Executing: kill -INT 19950
Executing: kill -KILL 19950
PASS: tracepoint_onthefly - otf_stress_prof_iter_2000 (survived)
=======

-- 
You are receiving this mail because:
You are the assignee for the bug.


Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]