[Bug runtime/21859] New: on rawhide, the context.exp test case causes a kernel warning

[Bug runtime/21859] New: on rawhide, the context.exp test case causes a kernel warning

[dsmith at redhat dot com]

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

            Bug ID: 21859
           Summary: on rawhide, the context.exp test case causes a kernel
                    warning
           Product: systemtap
           Version: unspecified
            Status: NEW
          Severity: normal
          Priority: P2
         Component: runtime
          Assignee: systemtap at sourceware dot org
          Reporter: dsmith at redhat dot com
  Target Milestone: ---

When the context.exp test case is run on rawhide
(4.13.0-0.rc1.git4.1.fc27.x86_64), I see the following on the console:

====
[ 1929.955050] ------------[ cut here ]------------
[ 1929.955541] WARNING: CPU: 0 PID: 4126 at kernel/module.c:262
module_assert_mutex+0x2a/0x30
[ 1929.956328] Modules linked in:
stap_318998d2b19fff82d6470ed9e62f751a_4126(OE) systemtap_test_module1(OE)
systemtap_test_module2(OE) sunrpc crct10dif_pclmul crc32_pclmul ppdev
ghash_clmulni_intel joydev parport_pc virtio_net virtio_balloon parport
i2c_piix4 pvpanic xfs libcrc32c virtio_console virtio_blk crc32c_intel
serio_raw virtio_pci virtio_ring virtio ata_generic pata_acpi
[ 1929.959398] CPU: 0 PID: 4126 Comm: stapio Tainted: G           OE  
4.13.0-0.rc1.git4.1.fc27.x86_64 #1
[ 1929.960284] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[ 1929.960811] task: ffff8c8d15c13300 task.stack: ffffa74501bac000
[ 1929.961367] RIP: 0010:module_assert_mutex+0x2a/0x30
[ 1929.961819] RSP: 0018:ffffa74501bafc88 EFLAGS: 00010246
[ 1929.962294] RAX: 0000000000000000 RBX: 000000000001777c RCX:
0000000000000000
[ 1929.962934] RDX: 0000000000000000 RSI: ffffffff8cfbb8d0 RDI:
0000000000000246
[ 1929.963563] RBP: ffffa74501bafc88 R08: 0000000000000075 R09:
ffffffffc0597618
[ 1929.964206] R10: ffffffff8cc882a0 R11: ffffffff8cc88640 R12:
ffffa74501bafda8
[ 1929.964865] R13: ffffffffc038c9a0 R14: ffffa74501bafda8 R15:
ffffffff8cb0cc20
[ 1929.965500] FS:  00007f9b2ba92740(0000) GS:ffff8c8d3fc00000(0000)
knlGS:0000000000000000
[ 1929.966220] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1929.966727] CR2: 00007f9b2a011fb8 CR3: 0000000036885000 CR4:
00000000001406f0
[ 1929.967401] Call Trace:
[ 1929.967646]  module_kallsyms_on_each_symbol+0x1d/0xa0
[ 1929.968137]  ? __stp_relay_wakeup_timer+0x90/0x90
[stap_318998d2b19fff82d6470ed9e62f751a_4126]
[ 1929.968966]  kallsyms_on_each_symbol+0xb9/0xc0
[ 1929.969382]  ? rcu_read_lock_sched_held+0x79/0x80
[ 1929.969833]  _stp_ctl_write_cmd+0xb03/0xf10
[stap_318998d2b19fff82d6470ed9e62f751a_4126]
[ 1929.970616]  ? full_proxy_write+0x5/0xb0
[ 1929.971014]  full_proxy_write+0x78/0xb0
[ 1929.971383]  __vfs_write+0x37/0x170
[ 1929.971733]  ? rcu_read_lock_sched_held+0x79/0x80
[ 1929.972190]  ? rcu_sync_lockdep_assert+0x2c/0x60
[ 1929.972632]  ? __sb_start_write+0x135/0x190
[ 1929.973048]  ? vfs_write+0x193/0x1c0
[ 1929.973401]  vfs_write+0xc6/0x1c0
[ 1929.973738]  SyS_write+0x58/0xc0
[ 1929.974058]  entry_SYSCALL_64_fastpath+0x1f/0xbe
[ 1929.974484] RIP: 0033:0x7f9b2b67420b
[ 1929.974815] RSP: 002b:00007fff0111f4d0 EFLAGS: 00000293 ORIG_RAX:
0000000000000001
[ 1929.975513] RAX: ffffffffffffffda RBX: 00007f9b2a012700 RCX:
00007f9b2b67420b
[ 1929.976174] RDX: 000000000000000c RSI: 00007fff0111f500 RDI:
0000000000000004
[ 1929.976814] RBP: 00007fff0111e7c0 R08: 0000000000000000 R09:
00007f9b2a012700
[ 1929.977502] R10: 00007f9b2a0129d0 R11: 0000000000000293 R12:
00007f9b2a011fc0
[ 1929.978198] R13: 00007fff0111e750 R14: 0000000000000000 R15:
0000000000000000
[ 1929.978877] Code: 00 0f 1f 44 00 00 8b 05 dd 89 ef 00 85 c0 75 02 f3 c3 55
be ff ff ff ff 48 c7 c7 d0 b8 fb 8c 48 89 e5 e8 ba 08 fb ff 85 c0 75 02 <0f> ff
5d c3 66 90 0f 1f 44 00 00 55 48 89 e5 53 48 89 fb e8 be 
[ 1929.980757] ---[ end trace 28fada5a9c0b7269 ]---
====

Note that this happens with the pre-bpf code also.

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

[Bug runtime/21859] on rawhide, the context.exp test case causes a kernel warning

[dsmith at redhat dot com]

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

--- Comment #1 from David Smith <dsmith at redhat dot com> ---
The following kernel commit changed module_kallsyms_on_each_symbol(), which is
called by kallsyms_on_each_symbol, to quit doing RCU-style module list
traversal and require the module_mutex:

====
commit 0be964be0d45084245673c971d72a4b51690231d
Author: Peter Zijlstra <peterz@infradead.org>
Date:   Wed May 27 11:09:35 2015 +0930

    module: Sanitize RCU usage and locking

    Currently the RCU usage in module is an inconsistent mess of RCU and
    RCU-sched, this is broken for CONFIG_PREEMPT where synchronize_rcu()
    does not imply synchronize_sched().

    Most usage sites use preempt_{dis,en}able() which is RCU-sched, but
    (most of) the modification sites use synchronize_rcu(). With the
    exception of the module bug list, which actually uses RCU.

    Convert everything over to RCU-sched.

    Furthermore add lockdep asserts to all sites, because it's not at all
    clear to me the required locking is observed, esp. on exported
    functions.
====

It looks like this patch was first included in kernel version 4.2. So, we'll
have to hold the module_mutex when calling kallsyms_on_each_symbol().

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

[Bug runtime/21859] on rawhide, the context.exp test case causes a kernel warning

[dsmith at redhat dot com]

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

David Smith <dsmith at redhat dot com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #2 from David Smith <dsmith at redhat dot com> ---
Fixed in commit 55594da.

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