From: "leisurelysw24 at gmail dot com" <sourceware-bugzilla@sourceware.org>
To: systemtap@sourceware.org
Subject: [Bug uprobes/24117] New: System crashes when probing a shared library
Date: Tue, 22 Jan 2019 09:51:00 -0000 [thread overview]
Message-ID: <bug-24117-6586@http.sourceware.org/bugzilla/> (raw)
https://sourceware.org/bugzilla/show_bug.cgi?id=24117
Bug ID: 24117
Summary: System crashes when probing a shared library
Product: systemtap
Version: unspecified
Status: UNCONFIRMED
Severity: normal
Priority: P2
Component: uprobes
Assignee: systemtap at sourceware dot org
Reporter: leisurelysw24 at gmail dot com
Target Milestone: ---
Hi,
I continuously encountered system crash when probing a shared libary on a
customized linux-based system. (However, probbing kernel function is fine.)
The result of systemtap building process is attached below. I've tried
systemtap-3.3 and systemtap-4.0 but got almost the same result. Also, the
kernel oops logs are also attached. Is there something missing when probbing a
library? Since the issue can be steadily re-produced, if there is anything I
could provide further, please let me know, thanks.
####### systemtap building process #######
Systemtap translator/driver (version 4.0/0.173, non-git sources)
[3199/9558]
Copyright (C) 2005-2018 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
tested kernel versions: 2.6.18 ... 4.19-rc7
enabled features: BOOST_STRING_REF NLS READLINE
Created temporary directory "/tmp/stapUMKO8R"
Session arch: x86_64 release: 4.14.24
Searched for library macro files:
"/usr/local/systemtap/share/systemtap/tapset/linux", found: 6, processed: 6
Searched for library macro files:
"/usr/local/systemtap/share/systemtap/tapset", found: 10, processed: 10
Searched: "/usr/local/systemtap/share/systemtap/tapset/linux/x86_64", found:
20, processed: 20
Searched: "/usr/local/systemtap/share/systemtap/tapset/linux", found: 404,
processed: 404
Searched: "/usr/local/systemtap/share/systemtap/tapset/x86_64", found: 1,
processed: 1
Searched: "/usr/local/systemtap/share/systemtap/tapset", found: 31, processed:
31
Pass 1: parsed user script and 472 library scripts using
102832virt/73236res/5240shr/68520data kb, in 450usr/40sys/483real ms.
derive-probes (location #0):
process.library("/lib/libuLinux_hal.so").function("PD_SMART_Get_ATA_Info") of
keyword at jtest.stp:3:1
probe PD_SMART_Get_ATA_Info@:-1 process=/lib/libuLinux_hal.so reloc=.dynamic
pc=0x4c4b0
Pass 2: analyzed script: 1 probe, 0 functions, 0 embeds, 0 globals using
104812virt/76436res/6328shr/70500data kb, in 10usr/0sys/10real ms.
function recursion-analysis: max-nesting 0 non-recursive
probe 0 ('process("/lib/libuLinux_hal.so").function("PD_SMART_Get_ATA_Info")')
locks nothing
1 statements for probe probe_6286
dump_unwindsyms /lib/libuLinux_hal.so index=0 base=0x10000
Pass 3: translated to C into
"/tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122_src.c" using
104952virt/76864res/6648shr/70640data kb, in 20usr/590sys/616real ms.
Pass 4: using cached
/root/.systemtap/cache/22/stapconf_221407b3fcfafc3ebaef66f97fabc8b0_825.h
Running env -uARCH -uKBUILD_EXTMOD -uCROSS_COMPILE -uKBUILD_IMAGE
-uKCONFIG_CONFIG -uINSTALL_PATH -uLD_LIBRARY_PATH
PATH=/usr/bin:/bin:/usr/local/toolchains/bin:/usr/local/sy
stemtap/bin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/bin/X11:/usr/local/sbin:/usr/local/bin
make -C /lib/modules/4.14.24/build M=/tmp/stapUMKO8R modules CONFIG_DEBUG_INFO=
CON
FIG_STACK_VALIDATION= ARCH=x86_64 --no-print-directory -j9
CC [M] /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122_src.o
CC [M] /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122_aux_0.o
LD [M] /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122.o
Building modules, stage 2.
MODPOST 1 modules
CC /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122.mod.o
LD [M] /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122.ko
Spawn waitpid result (0x0): 0
/root/.systemtap/cache/58/stap_58f2906e5f7287aa156151822bec2f00_1122.ko
Pass 4: compiled C into "stap_58f2906e5f7287aa156151822bec2f00_1122.ko" in
2230usr/1050sys/3005real ms.
Cleaning cache, interval reached 357 s > 300 s.
Copying /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122.ko to
/root/.systemtap/cache/58/stap_58f2906e5f7287aa156151822bec2f00_1122.ko
Copying /tmp/stapUMKO8R/stap_58f2906e5f7287aa156151822bec2f00_1122_src.c to
/root/.systemtap/cache/58/stap_58f2906e5f7287aa156151822bec2f00_1122.c
Copying /tmp/stapUMKO8R/stapconf_221407b3fcfafc3ebaef66f97fabc8b0_825.h to
/root/.systemtap/cache/22/stapconf_221407b3fcfafc3ebaef66f97fabc8b0_825.h
Running rm -rf /tmp/stapUMKO8R
Spawn waitpid result (0x0): 0
Removed temporary directory "/tmp/stapUMKO8R"
####### kernel oops trace #######
<7>[21149.354183] stap_58f2906e5f7287aa156151822bec2f0_32740 (jtest.stp):
systemtap: 4.0/0.173, base: ffffffffa06c6000, memory:
128data/48text/4ctx/2063net/131alloc kb, probes: 1
<4>[21149.366399]
<4>[21149.366402] ================================
<4>[21149.366403] WARNING: inconsistent lock state
<4>[21149.366405] 4.14.24 #1 Tainted: G O
<4>[21149.366406] --------------------------------
<4>[21149.366407] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
<4>[21149.366409] nmd/9125 [HC0[0]:SC0[0]:HE1:SE1] takes:
<4>[21149.366410] ((&(&cmd->abort_work)->timer)){+.?.}, at:
[<ffffffff8122e6d4>] igrab+0x14/0x50
<4>[21149.366414] {IN-SOFTIRQ-W} state was registered at:
<4>[21149.366417] lock_acquire+0xb9/0x200
<4>[21149.366420] call_timer_fn+0x65/0x350
<4>[21149.366421] run_timer_softirq+0x18f/0x5b0
<4>[21149.366424] __do_softirq+0x1d3/0x4cb
<4>[21149.366426] irq_exit+0xa0/0xb0
<4>[21149.366428] smp_apic_timer_interrupt+0xa5/0x2d0
<4>[21149.366429] apic_timer_interrupt+0x89/0x90
<4>[21149.366432] cpuidle_enter_state+0xf5/0x320
<4>[21149.366434] do_idle+0x18e/0x1e0
<4>[21149.366436] cpu_startup_entry+0x14/0x20
<4>[21149.366438] start_kernel+0x406/0x40e
<4>[21149.366440] secondary_startup_64+0xa5/0xb0
<4>[21149.366441] irq event stamp: 1786871
<4>[21149.366443] hardirqs last enabled at (1786871): [<ffffffff8122acef>]
prepend_path+0x1af/0x590
<4>[21149.366444] hardirqs last disabled at (1786870): [<ffffffff8122ac9c>]
prepend_path+0x15c/0x590
<4>[21149.366446] softirqs last enabled at (1785922): [<ffffffff820003ba>]
__do_softirq+0x3ba/0x4cb
<4>[21149.366448] softirqs last disabled at (1785905): [<ffffffff81089070>]
irq_exit+0xa0/0xb0
<4>[21149.366449]
<4>[21149.366449] other info that might help us debug this:
<4>[21149.366450] Possible unsafe locking scenario:
<4>[21149.366450]
<4>[21149.366451] CPU0
<4>[21149.366452] ----
<4>[21149.366453] lock((&(&cmd->abort_work)->timer));
<4>[21149.366454] <Interrupt>
<4>[21149.366455] lock((&(&cmd->abort_work)->timer));
<4>[21149.366457]
<4>[21149.366457] *** DEADLOCK ***
<4>[21149.366457]
<4>[21149.366458] 1 lock held by nmd/9125:
<4>[21149.366459] #0: (&ut->inode_lock){+.+.}, at: [<ffffffffa06cd857>]
stapiu_mmap_found+0x107/0x470 [stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366464]
<4>[21149.366464] stack backtrace:
<4>[21149.366466] CPU: 2 PID: 9125 Comm: nmd Tainted: G O 4.14.24
#1
<4>[21149.366467] Hardware name: INSYDE QV99/Type2 - Board Product Name1, BIOS
QV99IR31 07/16/2014
<4>[21149.366468] Call Trace:
<4>[21149.366471] dump_stack+0x5e/0x8e
<4>[21149.366473] print_usage_bug+0x1e7/0x1f9
<4>[21149.366475] mark_lock+0x513/0x5d0
<4>[21149.366477] __lock_acquire+0x3d8/0x19b0
<4>[21149.366480] ? stapiu_mmap_found+0x107/0x470
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366483] ? stapiu_mmap_found+0x107/0x470
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366485] ? lock_acquire+0xb9/0x200
<4>[21149.366487] lock_acquire+0xb9/0x200
<4>[21149.366489] ? igrab+0x14/0x50
<4>[21149.366491] _raw_spin_lock+0x27/0x40
<4>[21149.366492] ? igrab+0x14/0x50
<4>[21149.366494] igrab+0x14/0x50
<4>[21149.366496] stapiu_mmap_found+0x246/0x470
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366498] ? lock_acquire+0xb9/0x200
<4>[21149.366501] ? __stp_call_mmap_callbacks.part.71+0x5c/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366503] ? __stp_call_mmap_callbacks_for_task+0x18f/0x230
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366506] ? __stp_tf_quiesce_worker+0x114/0x130
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366508] ? task_work_run+0x74/0xb0
<4>[21149.366510] ? get_signal+0x946/0x970
<4>[21149.366512] ? find_held_lock+0x3f/0xc0
<4>[21149.366514] ? do_signal+0x1e/0x6b0
<4>[21149.366517] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366519] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366521] ? _raw_read_unlock_irqrestore+0x2d/0x50
<4>[21149.366523] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366525] ? __stp_utrace_task_finder_target_syscall_exit+0x4e/0x300
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366528] ? utrace_report_syscall_exit+0xf6/0x100
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366529] ? do_syscall_64+0x24a/0x460
<4>[21149.366531] ? do_syscall_64+0x26f/0x460
<4>[21149.366533] ? entry_SYSCALL_64_after_hwframe+0x42/0xb7
<1>[21149.366538] BUG: unable to handle kernel paging request at
0000000000769418
<1>[21149.366541] IP: queued_spin_lock_slowpath+0xe9/0x180
<6>[21149.366543] PGD 80000007fc89b067 P4D 80000007fc89b067 PUD 7fa38d067 PMD
8035a8067 PTE 0
<4>[21149.366548] Oops: 0002 [#1] SMP PTI
<4>[21149.366550] Modules linked in:
stap_58f2906e5f7287aa156151822bec2f0_32740(O) rfcomm iscsi_tcp(O)
libiscsi_tcp(O) libiscsi(O) scsi_transport_iscsi(O) fbdisk(O) xt_TCPMSS xt_LOG
ipt_MASQUERADE xt_REDIRECT nf_nat_redirect iptable_nat nf_nat_masquerade_ipv4
nf_nat_ipv4 nf_nat xt_policy cfg80211 dummy br_netfilter bridge stp bonding
xt_mark xt_set ip_set_hash_netiface ip_set_hash_net ip_set xt_connmark 8021q
uvcvideo videobuf2_v4l2 videobuf2_vmalloc videobuf2_memops videobuf2_core
snd_usb_caiaq snd_usb_audio snd_usbmidi_lib snd_seq_midi snd_rawmidi fnotify(O)
udf isofs iTCO_wdt kcopy(O) vfio_pci irqbypass vfio_virqfd vfio ipv6 pl2303
usbserial qm2_i2c(O) intel_ips drbd lru_cache flashcache(O) dm_tier_hro_algo
dm_thin_pool dm_bio_prison dm_persistent_data hal_netlink(O) k10temp coretemp
ixgbe mdio igb
<4>[21149.366588] e1000e mpt3sas scsi_transport_sas raid_class usb_storage
xhci_pci xhci_hcd usblp uhci_hcd ehci_pci ehci_hcd
<4>[21149.366595] CPU: 2 PID: 9125 Comm: nmd Tainted: G O 4.14.24
#1
<4>[21149.366597] Hardware name: INSYDE QV99/Type2 - Board Product Name1, BIOS
QV99IR31 07/16/2014
<4>[21149.366598] task: ffff8807f97421c0 task.stack: ffffc90000804000
<4>[21149.366600] RIP: 0010:queued_spin_lock_slowpath+0xe9/0x180
<4>[21149.366602] RSP: 0018:ffffc90000807bf8 EFLAGS: 00010206
<4>[21149.366604] RAX: 0000000000000b29 RBX: ffff88082caa2c78 RCX:
ffff88085e2a2a80
<4>[21149.366606] RDX: 0000000000769418 RSI: 000000002caa2c78 RDI:
ffff88082caa2c78
<4>[21149.366607] RBP: ffff88082caa2c78 R08: 00000000000c0000 R09:
0000000000000000
<4>[21149.366609] R10: ffffc90000807b90 R11: 0000000000000622 R12:
ffff8807f97421c0
<4>[21149.366610] R13: ffffffffa06d7258 R14: ffffffffa06d7198 R15:
0000000000000000
<4>[21149.366612] FS: 00007fb94937f700(0000) GS:ffff88085e280000(0000)
knlGS:0000000000000000
<4>[21149.366613] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[21149.366615] CR2: 0000000000769418 CR3: 00000007ff7c4001 CR4:
00000000001606e0
<4>[21149.366616] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
<4>[21149.366618] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
0000000000000400
<4>[21149.366619] Call Trace:
<4>[21149.366622] do_raw_spin_lock+0x8a/0x90
<4>[21149.366624] igrab+0x14/0x50
<4>[21149.366627] stapiu_mmap_found+0x246/0x470
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366630] ? lock_acquire+0xb9/0x200
<4>[21149.366633] ? __stp_call_mmap_callbacks.part.71+0x5c/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366637] ? __stp_call_mmap_callbacks_for_task+0x18f/0x230
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366640] ? __stp_tf_quiesce_worker+0x114/0x130
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366643] ? task_work_run+0x74/0xb0
<4>[21149.366645] ? get_signal+0x946/0x970
<4>[21149.366647] ? find_held_lock+0x3f/0xc0
<4>[21149.366650] ? do_signal+0x1e/0x6b0
<4>[21149.366653] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366656] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366658] ? _raw_read_unlock_irqrestore+0x2d/0x50
<4>[21149.366661] ? __stp_tf_get_map_entry+0x96/0xb0
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366664] ? __stp_utrace_task_finder_target_syscall_exit+0x4e/0x300
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366667] ? utrace_report_syscall_exit+0xf6/0x100
[stap_58f2906e5f7287aa156151822bec2f0_32740]
<4>[21149.366669] ? do_syscall_64+0x24a/0x460
<4>[21149.366671] ? do_syscall_64+0x26f/0x460
<4>[21149.366674] ? entry_SYSCALL_64_after_hwframe+0x42/0xb7
<4>[21149.366677] Code: c1 e0 10 45 31 c9 85 c0 74 44 48 89 c2 c1 e8 12 48 c1
ea 0c 83 e8 01 83 e2 30 48 98 48 81 c2 80 2a 02 00 48 03 14 c5 00 55 70 82 <48>
89 0a 8b 41 08 85 c0 75 09 f3 90 8b 41 08 85 c0 74 f7 4c 8b
<1>[21149.366709] RIP: queued_spin_lock_slowpath+0xe9/0x180 RSP:
ffffc90000807bf8
<4>[21149.366710] CR2: 0000000000769418
<4>[21149.366713] ---[ end trace aa625e330e554047 ]---
<3>[21149.368642] BUG: sleeping function called from invalid context at
./include/linux/percpu-rwsem.h:34
<3>[21149.368644] in_atomic(): 1, irqs_disabled(): 1, pid: 9125, name: nmd
<4>[21149.368646] INFO: lockdep is turned off.
<4>[21149.368647] irq event stamp: 1786871
<4>[21149.368650] hardirqs last enabled at (1786871): [<ffffffff8122acef>]
prepend_path+0x1af/0x590
<4>[21149.368652] hardirqs last disabled at (1786870): [<ffffffff8122ac9c>]
prepend_path+0x15c/0x590
<4>[21149.368654] softirqs last enabled at (1785922): [<ffffffff820003ba>]
__do_softirq+0x3ba/0x4cb
<4>[21149.368657] softirqs last disabled at (1785905): [<ffffffff81089070>]
irq_exit+0xa0/0xb0
<4>[21149.368659] CPU: 2 PID: 9125 Comm: nmd Tainted: G D O 4.14.24
#1
<4>[21149.368660] Hardware name: INSYDE QV99/Type2 - Board Product Name1, BIOS
QV99IR31 07/16/2014
<4>[21149.368661] Call Trace:
<4>[21149.368664] dump_stack+0x5e/0x8e
<4>[21149.368667] ___might_sleep+0x21d/0x250
<4>[21149.368669] exit_signals+0x1b/0x210
<4>[21149.368671] do_exit+0xad/0xce0
<4>[21149.368674] ? do_syscall_64+0x26f/0x460
<4>[21149.368677] rewind_stack_do_exit+0x17/0x20
<6>[21149.368694] note: nmd[9125] exited with preempt_count 1
<3>[21149.369396] utrace_free:797 * task_work_cancel() failed for
utrace_resume? task ffff8807f97421c0, 9125, nmd, 0x0 0x0
##### end #######
--
You are receiving this mail because:
You are the assignee for the bug.
next reply other threads:[~2019-01-22 9:51 UTC|newest]
Thread overview: 6+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-01-22 9:51 leisurelysw24 at gmail dot com [this message]
2019-01-30 22:06 ` [Bug uprobes/24117] " me at serhei dot io
2019-01-31 4:35 ` leisurelysw24 at gmail dot com
2019-01-31 20:04 ` me at serhei dot io
2019-02-01 2:06 ` leisurelysw24 at gmail dot com
2019-07-29 1:54 ` leisurelysw24 at gmail dot com
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=bug-24117-6586@http.sourceware.org/bugzilla/ \
--to=sourceware-bugzilla@sourceware.org \
--cc=systemtap@sourceware.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).