7:55 a.m.
----- hutao(a)cn.fujitsu.com wrote:
On Thu, Sep 02, 2010 at 03:46:00PM +0800, hutao(a)cn.fujitsu.com
wrote:
> Hi,
>
> I got a problem where it seemed crash got a bad backtrace.
> The problem occurred under the following conditions:
> On a qemu guest system loading a module that stuck at
> the init function(say, call a function that did deadlooping),
> then dumped the guest by `virsh dump vm dumpfile', and run
> crash on the dumpfile.
>
> The module is:
>
> ---
> #include <linux/module.h>
>
> int endless_loop(void)
> {
> printk("endless loop\n");
> while (1);
>
> return 0;
> }
>
> int __init endless_init(void)
> {
> endless_loop();
>
> return 0;
> }
> module_init(endless_init);
>
> MODULE_LICENSE("GPL");
> ---
>
> crash bt command got:
>
> crash> bt -a
> PID: 0 TASK: ffffffff81648020 CPU: 0 COMMAND: "swapper"
> #0 [ffffffff81601e08] schedule at ffffffff813e8a49
> #1 [ffffffff81601e18] apic_timer_interrupt at ffffffff8100344e
> #2 [ffffffff81601ea0] need_resched at ffffffff8100970c
> #3 [ffffffff81601eb0] default_idle at ffffffff81009f6b
> #4 [ffffffff81601ec0] cpu_idle at ffffffff81001bf5
>
> PID: 1088 TASK: ffff88001dda2d60 CPU: 1 COMMAND: "insmod"
> #0 [ffff88001e751dc8] schedule at ffffffff813e8a49
> #1 [ffff88001e751dd0] schedule at ffffffff813e8aec
> #2 [ffff88001e751e80] preempt_schedule_irq at ffffffff813e8c90
> #3 [ffff88001e751e90] retint_kernel at ffffffff813eab86
> #4 [ffff88001e751f20] do_one_initcall at ffffffff81000210
> #5 [ffff88001e751f50] sys_init_module at ffffffff8106b7ca
> #6 [ffff88001e751f80] system_call_fastpath at ffffffff81002a82
> RIP: 00007f761bb58b7a RSP: 00007fff67a43120 RFLAGS: 00010206
> RAX: 00000000000000af RBX: ffffffff81002a82 RCX: 0000000000020010
> RDX: 0000000000b96010 RSI: 00000000000163da RDI: 0000000000b96030
> RBP: 0000000000b96010 R8: 0000000000010011 R9: 0000000000080000
> R10: 00007f761bb4b140 R11: 0000000000000202 R12: 00000000000163da
> R13: 00007fff67a44985 R14: 00000000000163da R15: 0000000000b96010
> ORIG_RAX: 00000000000000af CS: 0033 SS: 002b
>
> Does it lose some function calls between do_one_initcall and retint_kernel?
> (endless_loop <- endless_init)
>
In addition, if we don't stick in the init function (there is still a deadloop
somewhere in module but triggered by, say, reading a /proc file) then the backtrace
outputed by crash is correct.
When you say "correct", I presume that you see your module functions as frames.
But if you also see the backtrace starting with "schedule", then it's just
luck
that the backtrace bumped into your module functions. It just so happened that
when walking back from schedule(), it "mistakenly" stumbled upon your
module's
functions.
In the example above, I presume that when trying to backtrace from retint_kernel(),
it stepped over your module's "loop" functions that were called via
do_one_initcall().
That's why I suggest that you should probably see them on the kernel stack in
between ffff88001e751e90 and ffff88001e751f20 if you use "bt -t". That is what
"bt -t" is for -- the "bt" command is never guaranteed to be correct.
Dave
2:43 a.m.
New subject: crash does not get proper backtrace?
On Thu, Sep 02, 2010 at 08:55:38AM -0400, Dave Anderson wrote:
----- hutao(a)cn.fujitsu.com wrote:
> On Thu, Sep 02, 2010 at 03:46:00PM +0800, hutao(a)cn.fujitsu.com wrote:
> > Hi,
> >
> > I got a problem where it seemed crash got a bad backtrace.
> > The problem occurred under the following conditions:
> > On a qemu guest system loading a module that stuck at
> > the init function(say, call a function that did deadlooping),
> > then dumped the guest by `virsh dump vm dumpfile', and run
> > crash on the dumpfile.
> >
> > The module is:
> >
> > ---
> > #include <linux/module.h>
> >
> > int endless_loop(void)
> > {
> > printk("endless loop\n");
> > while (1);
> >
> > return 0;
> > }
> >
> > int __init endless_init(void)
> > {
> > endless_loop();
> >
> > return 0;
> > }
> > module_init(endless_init);
> >
> > MODULE_LICENSE("GPL");
> > ---
> >
> > crash bt command got:
> >
> > crash> bt -a
> > PID: 0 TASK: ffffffff81648020 CPU: 0 COMMAND: "swapper"
> > #0 [ffffffff81601e08] schedule at ffffffff813e8a49
> > #1 [ffffffff81601e18] apic_timer_interrupt at ffffffff8100344e
> > #2 [ffffffff81601ea0] need_resched at ffffffff8100970c
> > #3 [ffffffff81601eb0] default_idle at ffffffff81009f6b
> > #4 [ffffffff81601ec0] cpu_idle at ffffffff81001bf5
> >
> > PID: 1088 TASK: ffff88001dda2d60 CPU: 1 COMMAND: "insmod"
> > #0 [ffff88001e751dc8] schedule at ffffffff813e8a49
> > #1 [ffff88001e751dd0] schedule at ffffffff813e8aec
> > #2 [ffff88001e751e80] preempt_schedule_irq at ffffffff813e8c90
> > #3 [ffff88001e751e90] retint_kernel at ffffffff813eab86
> > #4 [ffff88001e751f20] do_one_initcall at ffffffff81000210
> > #5 [ffff88001e751f50] sys_init_module at ffffffff8106b7ca
> > #6 [ffff88001e751f80] system_call_fastpath at ffffffff81002a82
> > RIP: 00007f761bb58b7a RSP: 00007fff67a43120 RFLAGS: 00010206
> > RAX: 00000000000000af RBX: ffffffff81002a82 RCX: 0000000000020010
> > RDX: 0000000000b96010 RSI: 00000000000163da RDI: 0000000000b96030
> > RBP: 0000000000b96010 R8: 0000000000010011 R9: 0000000000080000
> > R10: 00007f761bb4b140 R11: 0000000000000202 R12: 00000000000163da
> > R13: 00007fff67a44985 R14: 00000000000163da R15: 0000000000b96010
> > ORIG_RAX: 00000000000000af CS: 0033 SS: 002b
> >
> > Does it lose some function calls between do_one_initcall and retint_kernel?
> > (endless_loop <- endless_init)
> >
>
> In addition, if we don't stick in the init function (there is still a deadloop
> somewhere in module but triggered by, say, reading a /proc file) then the backtrace
> outputed by crash is correct.
When you say "correct", I presume that you see your module functions as
frames.
But if you also see the backtrace starting with "schedule", then it's just
luck
that the backtrace bumped into your module functions. It just so happened that
when walking back from schedule(), it "mistakenly" stumbled upon your
module's
functions.
In the example above, I presume that when trying to backtrace from retint_kernel(),
it stepped over your module's "loop" functions that were called via
do_one_initcall().
That's why I suggest that you should probably see them on the kernel stack in
between ffff88001e751e90 and ffff88001e751f20 if you use "bt -t". That is
what
"bt -t" is for -- the "bt" command is never guaranteed to be correct.
Nothing new in between ffff88001e751e90 and ffff88001e751f20 with `bt -at':
crash> bt -at
PID: 0 TASK: ffffffff81648020 CPU: 0 COMMAND: "swapper"
START: schedule at ffffffff813e8a49
[ffffffff81601e18] apic_timer_interrupt at ffffffff8100344e
[ffffffff81601e60] __atomic_notifier_call_chain at ffffffff813ed799
[ffffffff81601ea0] need_resched at ffffffff8100970c
[ffffffff81601eb0] default_idle at ffffffff81009f6b
[ffffffff81601ec0] cpu_idle at ffffffff81001bf5
[ffffffff81601f10] rest_init at ffffffff813d72ec
[ffffffff81601f30] start_kernel at ffffffff816e1d77
[ffffffff81601f40] command_line at ffffffff81718e90
[ffffffff81601f70] x86_64_start_reservations at ffffffff816e12ac
[ffffffff81601f90] x86_64_start_kernel at ffffffff816e13a8
PID: 1088 TASK: ffff88001dda2d60 CPU: 1 COMMAND: "insmod"
START: schedule at ffffffff813e8a49
[ffff88001e751dd0] schedule at ffffffff813e8aec
[ffff88001e751e40] get_parent_ip at ffffffff8102f193
[ffff88001e751e60] sub_preempt_count at ffffffff813ed62c
[ffff88001e751e70] need_resched at ffffffff8102a975
[ffff88001e751e80] preempt_schedule_irq at ffffffff813e8c90
[ffff88001e751e90] retint_kernel at ffffffff813eab86
[ffff88001e751f20] do_one_initcall at ffffffff81000210
[ffff88001e751f50] sys_init_module at ffffffff8106b7ca
[ffff88001e751f80] system_call_fastpath at ffffffff81002a82
RIP: 00007f761bb58b7a RSP: 00007fff67a43120 RFLAGS: 00010206
RAX: 00000000000000af RBX: ffffffff81002a82 RCX: 0000000000020010
RDX: 0000000000b96010 RSI: 00000000000163da RDI: 0000000000b96030
RBP: 0000000000b96010 R8: 0000000000010011 R9: 0000000000080000
R10: 00007f761bb4b140 R11: 0000000000000202 R12: 00000000000163da
R13: 00007fff67a44985 R14: 00000000000163da R15: 0000000000b96010
ORIG_RAX: 00000000000000af CS: 0033 SS: 002b
crash>
This is the related part of output of `bt -ar' in case you're interested:
ffff88001e751e60: sub_preempt_count+146 ffff88001e751e78
ffff88001e751e70: need_resched+30 ffff88001e751e88
ffff88001e751e80: preempt_schedule_irq+82 ffff88001e751f18
ffff88001e751e90: retint_kernel+38 ffff88001e751dd8
ffff88001e751ea0: 0000000000000000 0000000000000004
ffff88001e751eb0: 0000000000000000 ffff88001e751fd8
ffff88001e751ec0: 0000000000000000 0000000000000001
ffff88001e751ed0: 0000000000000000 ffffffffa00f9000
ffff88001e751ee0: ffffffffffffff10 ffffffffa00f9004
ffff88001e751ef0: 0000000000000010 0000000000000246
ffff88001e751f00: ffff88001e751f18 0000000000000018
ffff88001e751f10: ffff8800ffffffff ffff88001e751f48
ffff88001e751f20: do_one_initcall+122 __this_module
ffff88001e751f30: 0000000000000000 0000000000020000
ffff88001e751f40: 0000000000b96030 ffff88001e751f78
ffff88001e751f50: sys_init_module+196 0000000000b96010
ffff88001e751f60: 00000000000163da 00007fff67a44985
ffff88001e751f70: 00000000000163da 0000000000b96010
ffff88001e751f80: system_call_fastpath+22 0000000000000202
ffff88001e751f90: 00007f761bb4b140 0000000000080000
ffff88001e751fa0: 0000000000010011 00000000000000af
ffff88001e751fb0: 0000000000020010 0000000000b96010
ffff88001e751fc0: 00000000000163da 0000000000b96030
ffff88001e751fd0: 00000000000000af 00007f761bb58b7a
ffff88001e751fe0: 0000000000000033 0000000000010206
ffff88001e751ff0: 00007fff67a43120 000000000000002b
and `sym -m endless':
crash> sym -m endless
ffffffffa00f6000 MODULE START: endless
ffffffffa00f6000 (?) endless_loop
ffffffffa00f6030 (r) __ksymtab_endless_loop
ffffffffa00f6040 (r) __kstrtab_endless_loop
ffffffffa00f6050 (d) __this_module
ffffffffa00f6345 MODULE END: endless
crash>
--
Thanks,
Hu Tao
5537
days inactive
5538
days old
devel@lists.crash-utility.osci.io
1 comments
2 participants
participants (2)
-
Dave Anderson -
hutao＠cn.fujitsu.com