9:34 p.m.
Hello Dave,
The attached patches are used to display hrtimers.
To see detailed information, can refer to the patches.
--
--
Regards
Qiao Nuohan
10:52 a.m.
----- Original Message -----
Hello Dave,
The attached patches are used to display hrtimers.
To see detailed information, can refer to the patches.
--
Regards
Qiao Nuohan
Hi Qiao,
I ran this option through my set of sample vmcores, and have a couple
comments/suggestions.
A few of the sample vmcores generated bad rb_node.last virtual addresses,
and when they do, the command is aborted. For example:
$ crash -s 2.6.32-313.el6_softlockup/vmcore 2.6.32-313.el6_softlockup/vmlinux.gz
crash> timer -r
UPTIME: 300039(1000HZ)
cpu: 0
clock: 0
.base: ffff8800282115a8
.offset: 1354043557752205725
.get_time: ktime_get_real
EXPIRES HRTIMER FUNCTION
(empty)
clock: 1
.base: ffff8800282115e8
.offset: 0
.get_time: ktime_get
EXPIRES HRTIMER FUNCTION
300040000000-300040000000 ffff8800282116a0 ffffffff810a4b70
<tick_sched_timer>
3660368239466-3660368239466 ffff880224f07c68 ffffffff81071c00 <it_real_fn>
3660700491472-3660700491472 ffff880224f07068 ffffffff81071c00 <it_real_fn>
14461470907794-14461570907794 ffff88022750fa68 ffffffff81098160
<hrtimer_wakeup>
clock: 2
.base: ffff880028211628
.offset: 0
.get_time:
timer: invalid kernel virtual address: 1bc2f type: "rb_node last"
crash>
Here are some other vmcore examples where it failed similarly:
timer: invalid kernel virtual address: 1 type: "rb_node last"
timer: invalid kernel virtual address: 1ffffffff type: "rb_node last"
timer: invalid kernel virtual address: 1 type: "rb_node last"
timer: invalid kernel virtual address: 1 type: "rb_node last"
Perhaps there could be a way to pre-verify the addresses with
accessible(), and if the address is bogus, display an error message,
but allow the command to continue on with the other cpus?
And secondly, I ran into numerous examples of runaway commands
that loop over the same hrtimer entries. The kernels were typically
taken with the "snap.so" extension module, or where the dumpfiles
were taken with "virsh dump" -- but not always.
For examples:
$ crash -s 2.6.18-152.el5_HVM_virsh_dump/vmcore
2.6.18-152.el5_HVM_virsh_dump/vmlinux.gz
... [ cut ] ...
cpu: 1
clock: 0
.base: ffff810009580aa0
.get_time: ktime_get_real
EXPIRES HRTIMER FUNCTION
(empty)
clock: 1
.base: ffff810009580ae0
.get_time: ktime_get
EXPIRES HRTIMER FUNCTION
901601121855 ffff810034107ee8 ffffffff800a2536 <hrtimer_wakeup>
930465261855 ffff81003c22b5b0 ffffffff80093ced <it_real_fn>
922835889855 ffff81003333bee8 ffffffff800a2536 <hrtimer_wakeup>
930465261855 ffff81003c22b5b0 ffffffff80093ced <it_real_fn>
922835889855 ffff81003333bee8 ffffffff800a2536 <hrtimer_wakeup>
930465261855 ffff81003c22b5b0 ffffffff80093ced <it_real_fn>
922835889855 ffff81003333bee8 ffffffff800a2536 <hrtimer_wakeup>
930465261855 ffff81003c22b5b0 ffffffff80093ced <it_real_fn>
922835889855 ffff81003333bee8 ffffffff800a2536 <hrtimer_wakeup>
930465261855 ffff81003c22b5b0 ffffffff80093ced <it_real_fn>
922835889855 ffff81003333bee8 ffffffff800a2536 <hrtimer_wakeup>
... [ forever ] ....
$ crash -s snapshot-3.1.7-1.fc16/vmcore snapshot-3.1.7-1.fc16/vmlinux.gz
crash> timer -r
... [ cut ] ...
cpu: 6
clock: 0
.base: ffff88003e2ce180
.offset: 0
.get_time: ktime_get
EXPIRES HRTIMER FUNCTION
1689390000000-1689390000000 ffff88003e2ce280 ffffffff8109f650
<tick_sched_timer>
1692446941251-1692446941251 ffff88003e2ce400 ffffffff810d9790
<watchdog_timer_fn>
3628519841476-3628519891476 ffff880033fd5eb8 ffffffff81091b70 <hrtimer_wakeup>
1689390000000-1689390000000 ffff88003e2ce280 ffffffff8109f650
<tick_sched_timer>
1692446941251-1692446941251 ffff88003e2ce400 ffffffff810d9790
<watchdog_timer_fn>
3628519841476-3628519891476 ffff880033fd5eb8 ffffffff81091b70 <hrtimer_wakeup>
1689390000000-1689390000000 ffff88003e2ce280 ffffffff8109f650
<tick_sched_timer>
1692446941251-1692446941251 ffff88003e2ce400 ffffffff810d9790
<watchdog_timer_fn>
3628519841476-3628519891476 ffff880033fd5eb8 ffffffff81091b70 <hrtimer_wakeup>
1689390000000-1689390000000 ffff88003e2ce280 ffffffff8109f650
<tick_sched_timer>
1692446941251-1692446941251 ffff88003e2ce400 ffffffff810d9790
<watchdog_timer_fn>
3628519841476-3628519891476 ffff880033fd5eb8 ffffffff81091b70 <hrtimer_wakeup>
1689390000000-1689390000000 ffff88003e2ce280 ffffffff8109f650
<tick_sched_timer>
... [ forever ] ...
Maybe you can use hq_open()/hq_enter()/hq_close() on the hrtimer addresses
to prevent this from happening, warn the user when it does, and continue on
with the next cpu?
Thanks,
Dave
4:05 a.m.
Hello Dave,
Changed according to your suggestions. But need to add some explanation
here.
change 1:
Perhaps there could be a way to pre-verify the addresses with
accessible(), and if the address is bogus, display an error message,
but allow the command to continue on with the other cpus?
Error comes from rb_last() which used to calculate the space for
printing expires.
I fixed rb_last(), adding pre-verify the addresses. But I didn't use
rb_last() any more, for change 2 helps to find the last hrtimer.
change 2:
Maybe you can use hq_open()/hq_enter()/hq_close() on the hrtimer addresses
to prevent this from happening, warn the user when it does, and continue on
with the next cpu?
As you suggested.
change3:
When doing some snap test, I found rb_node's data may be destroyed, so
I also fixed other rbtree manipulation functions to avoid abort of
command.
--
--
Regards
Qiao Nuohan
3:15 p.m.
----- Original Message -----
Hello Dave,
Changed according to your suggestions. But need to add some explanation
here.
change 1:
> Perhaps there could be a way to pre-verify the addresses with
> accessible(), and if the address is bogus, display an error message,
> but allow the command to continue on with the other cpus?
Error comes from rb_last() which used to calculate the space for
printing expires.
I fixed rb_last(), adding pre-verify the addresses. But I didn't use
rb_last() any more, for change 2 helps to find the last hrtimer.
change 2:
>
> Maybe you can use hq_open()/hq_enter()/hq_close() on the hrtimer addresses
> to prevent this from happening, warn the user when it does, and continue on
> with the next cpu?
As you suggested.
change3:
When doing some snap test, I found rb_node's data may be destroyed, so
I also fixed other rbtree manipulation functions to avoid abort of
command.
Hi Qiao,
Thanks -- this second version makes it through my set of test kernels
successfully. The only vmcore I have that needs examination is this one,
where a softlockup timeout occurred:
crash> bt
PID: 7589 TASK: ffff8802292fa040 CPU: 0 COMMAND: "crash"
#0 [ffff880028203ce0] machine_kexec at ffffffff810329db
#1 [ffff880028203d40] crash_kexec at ffffffff810bdbd2
#2 [ffff880028203e10] panic at ffffffff815097a9
#3 [ffff880028203e90] watchdog_timer_fn at ffffffff810de51d
#4 [ffff880028203ec0] __run_hrtimer at ffffffff810986ee
#5 [ffff880028203f10] hrtimer_interrupt at ffffffff81098a56
#6 [ffff880028203f90] smp_apic_timer_interrupt at ffffffff8151350b
#7 [ffff880028203fb0] apic_timer_interrupt at ffffffff8100bc13
--- <IRQ stack> ---
#8 [ffff8802292a1df8] apic_timer_interrupt at ffffffff8100bc13
[exception RIP: copy_user_generic_string+45]
RIP: ffffffff81283ddd RSP: ffff8802292a1ea0 RFLAGS: 00010246
RAX: ffff8802292a0000 RBX: ffff8802292a1ee8 RCX: 0000000000000200
RDX: 0000000000000000 RSI: ffff880020000000 RDI: 0000000000d91dc0
RBP: ffffffff8100bc0e R8: ffffffff81346e70 R9: 0000000000000001
R10: 0000000000105c52 R11: 0000000000000246 R12: 0000000000d91dc0
R13: 0000000000020000 R14: 0000000000000000 R15: 0000000020000000
ORIG_RAX: ffffffffffffff10 CS: 0010 SS: 0018
#9 [ffff8802292a1ea0] crash_read at ffffffff81346fbd
#10 [ffff8802292a1ef0] vfs_read at ffffffff8117fd65
#11 [ffff8802292a1f30] sys_read at ffffffff8117fea1
#12 [ffff8802292a1f80] system_call_fastpath at ffffffff8100b0f2
RIP: 00007f3a6cb7e5f0 RSP: 00007fff740b8070 RFLAGS: 00000246
RAX: 0000000000000000 RBX: ffffffff8100b0f2 RCX: 00007f3a6cb7e5f0
RDX: 0000000000001000 RSI: 0000000000d91dc0 RDI: 0000000000000004
RBP: 0000000000000004 R8: 0000000020000000 R9: 0000000020000000
R10: 0000000000105c52 R11: 0000000000000246 R12: 0000000000001000
R13: 0000000000d91dc0 R14: 0000000000001000 R15: 0000000000d91dc0
ORIG_RAX: 0000000000000000 CS: 0033 SS: 002b
crash>
And the timer command fails like so, again, without being able to
complete the rest of the cpus:
crash> timer -r
UPTIME: 300039(1000HZ)
cpu: 0
clock: 0
.base: ffff8800282115a8
.offset: 1354043557752205725
.get_time: ktime_get_real
EXPIRES HRTIMER FUNCTION
(empty)
clock: 1
.base: ffff8800282115e8
.offset: 0
.get_time: ktime_get
EXPIRES HRTIMER FUNCTION
300040000000-300040000000 ffff8800282116a0 ffffffff810a4b70
<tick_sched_timer>
3660368239466-3660368239466 ffff880224f07c68 ffffffff81071c00 <it_real_fn>
3660700491472-3660700491472 ffff880224f07068 ffffffff81071c00 <it_real_fn>
14461470907794-14461570907794 ffff88022750fa68 ffffffff81098160
<hrtimer_wakeup>
clock: 2
.base: ffff880028211628
.offset: 0
.get_time:
timer: invalid kernel virtual address: 2c type: "ktime_t tv64"
crash>
Presumably the kernel was in the midst of tinkering with the hrtimer-related
structures, and that was what causes the bad readmem() above. But I'm
thinking that since softlockups are a fairly common cause of kernel crashes,
that this option should be able to handle it better than above?
I've put copies of the vmlinux/vmcore pair above here for you to take a look:
http://people.redhat.com/anderson/qiao
The next thing that needs to be reworked is the display itself.
I really don't like the ".base", ".offset" and
".get_time" lines,
primarily because none of the other crash commands do anything like
that. Also, the UPTIME display is kind of strange. It only applies to
the "ktime_get" type clocks, right?
I understand why you selected those particular fields -- although I can't
find a ".base" member in either the hr_clock_base or hrtimer_cpu_base
structures? But more importantly, what if a user wants to see the other
fields in either of those two data structures? There's no obvious
way to find their addresses.
Anyway, for consistency with other crash commands, I think that it's
more useful to display the hrtimer_cpu_base and hr_clock_base structure
addresses, and perhaps the most important fields within them, in tabular
form, grouped together something like:
crash> timer -r
CPU: 0
CLOCK: 0
HRTIMER_CPU_BASE HR_CLOCK_BASE OFFSET FUNCTION
<address> <address> <value> ktime_get
EXPIRES HRTIMER FUNCTION
396384243603-396384293603 ffff88003c905eb8 ffffffff8107da00
<hrtimer_wakeup>
397000645784-397004641782 ffff88003d2b1a58 ffffffff8107da00
<hrtimer_wakeup>
407501746988-407531746986 ffff88003c2b5a58 ffffffff8107da00
<hrtimer_wakeup>
446387171280-446446754509 ffff88003bb43908 ffffffff8107da00
<hrtimer_wakeup>
900000001418-900000001418 ffff8800368e53c0 ffffffff811c57d0
<timerfd_tmrproc>
CLOCK: 1
HRTIMER_CPU_BASE HR_CLOCK_BASE OFFSET FUNCTION
<address> <address> <value> ktime_get_real
EXPIRES HRTIMER FUNCTION
(empty)
CLOCK: 2
HRTIMER_CPU_BASE HR_CLOCK_BASE OFFSET FUNCTION
<address> <address> <value> ktime_get
EXPIRES HRTIMER FUNCTION
396366000000-396366000000 ffff88003fcce6a0 ffffffff810ac4a0
<tick_sched_timer>
394748203985-394749203930 ffff880039f4f908 ffffffff8107da00 <hrtimer_wakeup>
400056995196-400056995196 ffff88003fcce820 ffffffff810e2800
<watchdog_timer_fn>
3616558364176-3616558414176 ffff88003cf6beb8 ffffffff8107da00 <hrtimer_wakeup>
CPU: 1
...
I think a display like the above shows everything that you are doing
now -- plus a bit more.
What do you think?
Dave
3:29 p.m.
----- Original Message -----
Anyway, for consistency with other crash commands, I think that
it's
more useful to display the hrtimer_cpu_base and hr_clock_base structure
addresses, and perhaps the most important fields within them, in tabular
form, grouped together something like:
crash> timer -r
CPU: 0
CLOCK: 0
HRTIMER_CPU_BASE HR_CLOCK_BASE OFFSET FUNCTION
<address> <address> <value> ktime_get
EXPIRES HRTIMER FUNCTION
396384243603-396384293603 ffff88003c905eb8 ffffffff8107da00
<hrtimer_wakeup>
397000645784-397004641782 ffff88003d2b1a58 ffffffff8107da00
<hrtimer_wakeup>
407501746988-407531746986 ffff88003c2b5a58 ffffffff8107da00
<hrtimer_wakeup>
446387171280-446446754509 ffff88003bb43908 ffffffff8107da00
<hrtimer_wakeup>
900000001418-900000001418 ffff8800368e53c0 ffffffff811c57d0
<timerfd_tmrproc>
Actually, since the HRTIMER_CPU_CASE address display would
be redundant, perhaps something like this would be cleaner:
crash> timer -r
CPU: 0 HRTIMER_CPU_BASE: <address>
CLOCK: 0 HR_CLOCK_BASE: <address>
OFFSET FUNCTION
<value> ktime_get
EXPIRES HRTIMER FUNCTION
396384243603-396384293603 ffff88003c905eb8 ffffffff8107da00
<hrtimer_wakeup>
397000645784-397004641782 ffff88003d2b1a58 ffffffff8107da00
<hrtimer_wakeup>
407501746988-407531746986 ffff88003c2b5a58 ffffffff8107da00
<hrtimer_wakeup>
446387171280-446446754509 ffff88003bb43908 ffffffff8107da00
<hrtimer_wakeup>
900000001418-900000001418 ffff8800368e53c0 ffffffff811c57d0
<timerfd_tmrproc>
CLOCK: 1 HR_CLOCK_BASE: <address>
...
Dave
12:56 a.m.
Hello Dave,
The problem is fixed and I changed the display according to your
suggestion. Please check.
One more thing is about current time. I think current time is needed
when debugging, for debuggers can compare the expires of hrtimers with
current time.
When realizing this functionality, I once tried to use xtime plus
wall_to_monotonic. But then I found the value is not that correct. So I
use uptime here. Since it seems strange, what about changing the
display?
--
--
Regards
Qiao Nuohan
3:04 p.m.
----- Original Message -----
Hello Dave,
The problem is fixed and I changed the display according to your
suggestion. Please check.
I'm going to test it over the weekend on my sample set of vmcores
just to make sure the failure protection is still working.
I'm still not particularly happy about the display. For example, with
the older style without hrtimer_cpu_base addresses, I think it's
unnecessary to display the HRTIMER_BASES[] address next to each cpu
since the each address in the array is shown for each clock. Plus
the "ACTIVE TIMERS:" line is pretty much unnecessary, and perhaps
the OFFSET and GET_TIME fields can be put on one line.
Let me think some more about how it can be made more useful/clear.
One more thing is about current time. I think current time is needed
when debugging, for debuggers can compare the expires of hrtimers with
current time.
When realizing this functionality, I once tried to use xtime plus
wall_to_monotonic. But then I found the value is not that correct. So I
use uptime here. Since it seems strange, what about changing the
display?
If it's not readily obvious what it's showing, and how it relates to
the expire data, then I would leave it out.
One other suggestion...
I probably should have been a bit more clear about using
accessible() to prevent the command from aborting prematurely.
Your fixes do accomplish that, but, for example, while this
usage of accessible() makes perfect sense in your print_timer()
function:
+ if (!accessible((ulong)timer)) {
+ fprintf(fp, "(destroyed timer)\n");
+ return;
+ }
later on in the function, this usage is essentially redundant with
the subsequent readmem():
+ if (accessible((ulong)(timer + OFFSET(hrtimer_function)))) {
+ readmem((ulong)(timer + OFFSET(hrtimer_function)), KVADDR, &function,
+ sizeof(function), "hrtimer function", FAULT_ON_ERROR);
+ fprintf(fp, "%lx ", function);
+ fprintf(fp ,"<%s>", value_to_symstr(function, buf3, 0));
+ }
It can be done with one call by using RETURN_ON_ERROR|QUIET and
checking the return value:
if (readmem((ulong)(timer + OFFSET(hrtimer_function)), KVADDR, &function,
sizeof(function), "hrtimer function", RETURN_ON_ERROR|QUIET)) {
fprintf(fp, "%lx ", function);
fprintf(fp ,"<%s>", value_to_symstr(function, buf3, 0));
}
Thanks,
Dave
3:35 p.m.
Hi Qiao,
Clarify this for me -- the offset value for the ktime_get_real() timer is
presumably the current per-timer clock value for that timer:
cpu: 0 HRTIMER_CPU_BASE: ffff880004159d20
clock: 0 HRTIMER_CLOCK_BASE: ffff880004159d28
OFFSET: 1277723463192897448
GET_TIME: ktime_get_real
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
1277723709520405731-1277723709520455731 ffff88001cc71d18 ffffffff81093e00
<hrtimer_wakeup>
But what does an offset of 0 mean for ktime_get() timers?
clock: 1 HRTIMER_CLOCK_BASE: ffff880004159d68
OFFSET: 0
GET_TIME: ktime_get
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
205155628339-205156606338 ffff88001dfa1a68 ffffffff81093e00
<hrtimer_wakeup>
205500000000-205500000000 ffff880004159e20 ffffffff810a0290
<tick_sched_timer>
212807104852-212807154852 ffff88000355fea8 ffffffff81093e00
<hrtimer_wakeup>
221875226353-221905226352 ffff880003611a68 ffffffff81093e00
<hrtimer_wakeup>
237880877947-237880927947 ffff88001df2dea8 ffffffff81093e00
<hrtimer_wakeup>
254807591647-254877419646 ffff88001d67ba68 ffffffff81093e00
<hrtimer_wakeup>
347174079293-347174079293 ffff8800035edc68 ffffffff810701a0 <it_real_fn>
And for the old-style hrtimers, there is no offset value shown at all. What would
their expires values compare to?
clock: 1 HRTIMER_BASE: ffff810009006500
GET_TIME: ktime_get
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
614160200709018 ffff81042e432ab0 ffffffff80095103 <it_real_fn>
614160235717018 ffff8103d93681b0 ffffffff80095103 <it_real_fn>
Dave
4:06 a.m.
Hello Dave,
Sorry for late. And I think my last mail is not that clear, so I will
add some explanation here.
And firstly, some answers to your question.
1. offset means the offset of the clock to the monotonic time.
2. If offset is 0 or without offset, the clock gets the monotonic time
with it.
3. If offset is not 0, lick clock 0 on cpu 0, the time of this clock is
monotonic time together with the value of offset. Additionally,
expiration of the clock is also based on the offset.
If I want to compare expiration with current time, I should first add
offset with monotonic time(I use uptime in my command, for accurate time
is unable to get), then get the current time of the clock.
At 2013-3-2 5:35, Dave Anderson wrote:
Hi Qiao,
Clarify this for me -- the offset value for the ktime_get_real() timer is
presumably the current per-timer clock value for that timer:
cpu: 0 HRTIMER_CPU_BASE: ffff880004159d20
clock: 0 HRTIMER_CLOCK_BASE: ffff880004159d28
OFFSET: 1277723463192897448
GET_TIME: ktime_get_real
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
1277723709520405731-1277723709520455731 ffff88001cc71d18
ffffffff81093e00<hrtimer_wakeup>
But what does an offset of 0 mean for ktime_get() timers?
clock: 1 HRTIMER_CLOCK_BASE: ffff880004159d68
OFFSET: 0
GET_TIME: ktime_get
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
205155628339-205156606338 ffff88001dfa1a68
ffffffff81093e00<hrtimer_wakeup>
205500000000-205500000000 ffff880004159e20
ffffffff810a0290<tick_sched_timer>
212807104852-212807154852 ffff88000355fea8
ffffffff81093e00<hrtimer_wakeup>
221875226353-221905226352 ffff880003611a68
ffffffff81093e00<hrtimer_wakeup>
237880877947-237880927947 ffff88001df2dea8
ffffffff81093e00<hrtimer_wakeup>
254807591647-254877419646 ffff88001d67ba68
ffffffff81093e00<hrtimer_wakeup>
347174079293-347174079293 ffff8800035edc68 ffffffff810701a0<it_real_fn>
And for the old-style hrtimers, there is no offset value shown at all. What would
their expires values compare to?
clock: 1 HRTIMER_BASE: ffff810009006500
GET_TIME: ktime_get
ACTIVE TIMERS:
EXPIRES HRTIMER FUNCTION
614160200709018 ffff81042e432ab0 ffffffff80095103<it_real_fn>
614160235717018 ffff8103d93681b0 ffffffff80095103<it_real_fn>
Dave
--
Crash-utility mailing list
Crash-utility(a)redhat.com
https://www.redhat.com/mailman/listinfo/crash-utility
--
--
Regards
Qiao Nuohan
8:56 a.m.
----- Original Message -----
Hello Dave,
Sorry for late. And I think my last mail is not that clear, so I will
add some explanation here.
And firstly, some answers to your question.
1. offset means the offset of the clock to the monotonic time.
2. If offset is 0 or without offset, the clock gets the monotonic time
with it.
3. If offset is not 0, lick clock 0 on cpu 0, the time of this clock is
monotonic time together with the value of offset. Additionally,
expiration of the clock is also based on the offset.
If I want to compare expiration with current time, I should first add
offset with monotonic time(I use uptime in my command, for accurate time
is unable to get), then get the current time of the clock.
Right, so what I was saying is that it doesn't make much sense to
show "OFFSET: 0", and it's also confusing when nothing is shown on
the older versions.
Perhaps there could be a "NOW:" field, where you come up with
per-timer-type algorithms to show a value that relates to the
expires value?
And while you're at it, can you please remove the "HRTIMER_BASES[]"
and also clean up the unnecessary accessible() calls?
Thanks,
Dave
12:48 a.m.
Hello Dave,
It's done. I use *NOW* to replace *OFFSET*. Please check.
At 2013-3-6 22:56, Dave Anderson wrote:
----- Original Message -----
> Hello Dave,
>
> Sorry for late. And I think my last mail is not that clear, so I will
> add some explanation here.
>
> And firstly, some answers to your question.
>
> 1. offset means the offset of the clock to the monotonic time.
>
> 2. If offset is 0 or without offset, the clock gets the monotonic time
> with it.
>
> 3. If offset is not 0, lick clock 0 on cpu 0, the time of this clock is
> monotonic time together with the value of offset. Additionally,
> expiration of the clock is also based on the offset.
>
> If I want to compare expiration with current time, I should first add
> offset with monotonic time(I use uptime in my command, for accurate time
> is unable to get), then get the current time of the clock.
Right, so what I was saying is that it doesn't make much sense to
show "OFFSET: 0", and it's also confusing when nothing is shown on
the older versions.
Perhaps there could be a "NOW:" field, where you come up with
per-timer-type algorithms to show a value that relates to the
expires value?
And while you're at it, can you please remove the "HRTIMER_BASES[]"
and also clean up the unnecessary accessible() calls?
Thanks,
Dave
--
Crash-utility mailing list
Crash-utility(a)redhat.com
https://www.redhat.com/mailman/listinfo/crash-utility
--
--
Regards
Qiao Nuohan
12:26 p.m.
----- Original Message -----
Hello Dave,
It's done. I use *NOW* to replace *OFFSET*. Please check.
crash> timer -r
cpu: 0 HRTIMER_CPU_BASE: ffff88021e20e700
clock: 0 HRTIMER_CLOCK_BASE: ffff88021e20e740
NOW: 92474883 GET_TIME: ktime_get
EXPIRES HRTIMER FUNCTION
92475257224621-92475257274621 ffff880210d63eb8 ffffffff81085fc0
<hrtimer_wakeup>
92475337818743-92475338341742 ffff88020f1a9a68 ffffffff81085fc0
<hrtimer_wakeup>
92475708000000-92475708000000 ffff88021e20e960 ffffffff810b62a0
<tick_sched_timer>
92476040000000-92476040000000 ffff88021e20eae0 ffffffff810eb3e0
<watchdog_timer_fn>
92480244973869-92480245023869 ffff88021184beb8 ffffffff81085fc0
<hrtimer_wakeup>
92497170944250-92497200944249 ffff880210f05a68 ffffffff81085fc0
<hrtimer_wakeup>
92499263103403-92499293079402 ffff880211a19da8 ffffffff81085fc0
<hrtimer_wakeup>
93626419371172-93626419371172 ffff88020f97b7b8 ffffffff810654e0
<it_real_fn>
93626560930229-93626560930229 ffff88020f97d578 ffffffff810654e0
<it_real_fn>
94865820026579-94865920026579 ffff88020e365da8 ffffffff81085fc0
<hrtimer_wakeup>
Shouldn't the NOW value for the ktime_get timers be adjusted appropriate
to the EXPIRES values?
Dave
At 2013-3-6 22:56, Dave Anderson wrote:
>
>
> ----- Original Message -----
>> Hello Dave,
>>
>> Sorry for late. And I think my last mail is not that clear, so I
>> will
>> add some explanation here.
>>
>> And firstly, some answers to your question.
>>
>> 1. offset means the offset of the clock to the monotonic time.
>>
>> 2. If offset is 0 or without offset, the clock gets the monotonic
>> time
>> with it.
>>
>> 3. If offset is not 0, lick clock 0 on cpu 0, the time of this
>> clock is
>> monotonic time together with the value of offset. Additionally,
>> expiration of the clock is also based on the offset.
>>
>> If I want to compare expiration with current time, I should first
>> add
>> offset with monotonic time(I use uptime in my command, for
>> accurate time
>> is unable to get), then get the current time of the clock.
>
> Right, so what I was saying is that it doesn't make much sense to
> show "OFFSET: 0", and it's also confusing when nothing is shown on
> the older versions.
>
> Perhaps there could be a "NOW:" field, where you come up with
> per-timer-type algorithms to show a value that relates to the
> expires value?
>
> And while you're at it, can you please remove the "HRTIMER_BASES[]"
> and also clean up the unnecessary accessible() calls?
>
> Thanks,
> Dave
>
> --
> Crash-utility mailing list
> Crash-utility(a)redhat.com
> https://www.redhat.com/mailman/listinfo/crash-utility
>
>
--
--
Regards
Qiao Nuohan
--
Crash-utility mailing list
Crash-utility(a)redhat.com
https://www.redhat.com/mailman/listinfo/crash-utility
2:13 a.m.
Hello Dave,
Please ignore the last mail. I change the style of expires, for "xx-xx"
is a litter more difficult to be parsed. Please check.
At 2013-3-11 10:28, qiaonuohan wrote:
At 2013-3-9 2:26, Dave Anderson wrote:
> Shouldn't the NOW value for the ktime_get timers be adjusted appropriate
> to the EXPIRES values?
Done. I made a mistaken here, thanks for pointing it out!
--
Crash-utility mailing list
Crash-utility(a)redhat.com
https://www.redhat.com/mailman/listinfo/crash-utility
--
--
Regards
Qiao Nuohan
3:36 p.m.
----- Original Message -----
Hello Dave,
Please ignore the last mail. I change the style of expires, for "xx-xx"
is a litter more difficult to be parsed. Please check.
At 2013-3-11 10:28, qiaonuohan wrote:
> At 2013-3-9 2:26, Dave Anderson wrote:
>> Shouldn't the NOW value for the ktime_get timers be adjusted appropriate
>> to the EXPIRES values?
>
> Done. I made a mistaken here, thanks for pointing it out!
>
Hi Qiao,
I've been tinkering around with this latest version, and it works pretty well.
I've changed a few things:
(1) use option_not_supported() instead of command_not_supported() when used
with pre-hrtimer kernels.
(2) show the get_timer function in [brackets] on the same line as eacho of
the "CLOCK: ... lines".
(3) reversed the output of SOFTEXPIRES and EXPIRES, as it makes more
sense to show the lower value of the range (SOFTEXPIRES) first.
(4) displayed the NOW display (and changed it to "CURRENT") such that the
value is properly aligned above with the SOFTEXPIRES/EXPIRES value,
whichever is appropriate.
(4) in the case of unused timers, don't bother displaying the current
value or the headers -- it's just unnecessary clutter; it will just
display the "CLOCK: 1 HRTIMER_CLOCK_BASE ..." line followed by
"(empty)".
So for example, it would look like:
CPU: 63 HRTIMER_CPU_BASE: ffff88088e690f40
CLOCK: 0 HRTIMER_CLOCK_BASE: ffff88088e690f48 [ktime_get_real]
(empty)
CLOCK: 1 HRTIMER_CLOCK_BASE: ffff88088e690f88 [ktime_get]
CURRENT
3731204000000
SOFTEXPIRES EXPIRES HRTIMER FUNCTION
3731515000000 3731515000000 ffff88088e691040 ffffffff8109dff0
<tick_sched_timer>
3736464999849 3736464999849 ffff88088e691260 ffffffff810d5fa0
<watchdog_timer_fn>
And I'll rewrite the help.c stuff, using i386 examples so that the output
examples can fit within 80 columns.
Thanks,
Dave
2:24 a.m.
At 2013-3-12 4:36, Dave Anderson wrote:
I've been tinkering around with this latest version, and it works
pretty well.
I've changed a few things:
(1) use option_not_supported() instead of command_not_supported() when used
with pre-hrtimer kernels.
(2) show the get_timer function in [brackets] on the same line as eacho of
the "CLOCK: ... lines".
(3) reversed the output of SOFTEXPIRES and EXPIRES, as it makes more
sense to show the lower value of the range (SOFTEXPIRES) first.
(4) displayed the NOW display (and changed it to "CURRENT") such that the
value is properly aligned above with the SOFTEXPIRES/EXPIRES value,
whichever is appropriate.
(4) in the case of unused timers, don't bother displaying the current
value or the headers -- it's just unnecessary clutter; it will just
display the "CLOCK: 1 HRTIMER_CLOCK_BASE ..." line followed by
"(empty)".
So for example, it would look like:
CPU: 63 HRTIMER_CPU_BASE: ffff88088e690f40
CLOCK: 0 HRTIMER_CLOCK_BASE: ffff88088e690f48 [ktime_get_real]
(empty)
CLOCK: 1 HRTIMER_CLOCK_BASE: ffff88088e690f88 [ktime_get]
CURRENT
3731204000000
SOFTEXPIRES EXPIRES HRTIMER FUNCTION
3731515000000 3731515000000 ffff88088e691040
ffffffff8109dff0<tick_sched_timer>
3736464999849 3736464999849 ffff88088e691260
ffffffff810d5fa0<watchdog_timer_fn>
And I'll rewrite the help.c stuff, using i386 examples so that the output
examples can fit within 80 columns.
Got it, thanks for your description.
--
--
Regards
Qiao Nuohan
3:03 a.m.
New subject: timer: invalid list entry: 1
Hi,
I am getting folowing: I am unable to get whether there is memory corruption or crash
utility has problem displaying.
using crash utility version: 6.1.1
kernel version : 3.4.5+
I am getting following.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
TVEC_BASES[1]: dc85e000
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
384 c0a42ba8 c007260c <idle_worker_timeout>
4297862 dbec0dfc c007412c <delayed_work_timer_fn>
4297897 c162c6e0 c007412c <delayed_work_timer_fn>
4297962 dbec0ea0 c04a7cec <estimation_timer>
4297997 c162c7cc c007412c <delayed_work_timer_fn>
4300768 dcb36654 c007412c <delayed_work_timer_fn>
4309824 c0a20024 c0516718 <addrconf_verify>
4327762 dcaabf54 c0068ebc <process_timeout>
4327808 c162aea8 c007260c <idle_worker_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
Regards,
Oza.
8:24 a.m.
New subject: timer: invalid list entry: 1
----- Original Message -----
Hi,
I am getting folowing: I am unable to get whether there is memory
corruption or crash utility has problem displaying.
using crash utility version: 6.1.1
kernel version : 3.4.5+
I am getting following.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
TVEC_BASES[1]: dc85e000
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
384 c0a42ba8 c007260c <idle_worker_timeout>
4297862 dbec0dfc c007412c <delayed_work_timer_fn>
4297897 c162c6e0 c007412c <delayed_work_timer_fn>
4297962 dbec0ea0 c04a7cec <estimation_timer>
4297997 c162c7cc c007412c <delayed_work_timer_fn>
4300768 dcb36654 c007412c <delayed_work_timer_fn>
4309824 c0a20024 c0516718 <addrconf_verify>
4327762 dcaabf54 c0068ebc <process_timeout>
4327808 c162aea8 c007260c <idle_worker_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
Regards,
Oza.
It's impossible to answer without knowing the specifics.
It could be corruption, or perhaps the cpu 0 was manipulating
the timer chains when the kernel panicked, or perhaps there
is some off-the-wall condition that the crash utility has
never encountered.
Dave
Dave
11:28 p.m.
New subject: timer: invalid list entry: 1
I would give some more info.
It is dual core system. (ARM)
both core are stuck at wfi (wait for interrupt)
and we observe that the timer counter has one much ahead than the comparators.
so we never get a local timer interrupt, and nobody is there to wake the cpu up.
so we observe the freeze.
Regards,
Oza.
________________________________
From: Dave Anderson <anderson(a)redhat.com>
To: paawan oza <paawan1982(a)yahoo.com>; "Discussion list for crash utility
usage, maintenance and development" <crash-utility(a)redhat.com>
Sent: Thursday, 28 February 2013 7:54 PM
Subject: Re: [Crash-utility] timer: invalid list entry: 1
----- Original Message -----
Hi,
I am getting folowing: I am unable to get whether there is memory
corruption or crash utility has problem displaying.
using crash utility version: 6.1.1
kernel version : 3.4.5+
I am getting following.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
TVEC_BASES[1]: dc85e000
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
384 c0a42ba8 c007260c <idle_worker_timeout>
4297862 dbec0dfc c007412c <delayed_work_timer_fn>
4297897 c162c6e0 c007412c <delayed_work_timer_fn>
4297962 dbec0ea0 c04a7cec <estimation_timer>
4297997 c162c7cc c007412c <delayed_work_timer_fn>
4300768 dcb36654 c007412c <delayed_work_timer_fn>
4309824 c0a20024 c0516718 <addrconf_verify>
4327762 dcaabf54 c0068ebc <process_timeout>
4327808 c162aea8 c007260c <idle_worker_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
Regards,
Oza.
It's impossible to answer without knowing the specifics.
It could be corruption, or perhaps the cpu 0 was manipulating
the timer chains when the kernel panicked, or perhaps there
is some off-the-wall condition that the crash utility has
never encountered.
Dave
Dave
5:44 a.m.
New subject: timer: invalid list entry: 1
some more info:
I am debugging crash utility with gdb, and getting following stack trace.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
Breakpoint 2, do_list (ld=0xff961c78) at tools.c:3507
3507 error(INFO, "\ninvalid list entry: %lx\n",
next);
(gdb) bt
#0 do_list (ld=0xff961c78) at tools.c:3507
#1 0x0811de03 in do_timer_list (vec_kvaddr=3699761524, size=256, vec=0x85c9f40,
option=0x0, highest=0x0, tv=0xff962ec4) at kernel.c:6983
#2 0x0811c9d3 in dump_timer_data_tvec_bases_v2 () at kernel.c:6678
#3 0x0811afac in dump_timer_data () at kernel.c:6370
#4 0x0811af8a in cmd_timer () at kernel.c:6329
#5 0x080910a1 in exec_command () at main.c:818
#6 0x08090ec7 in main_loop () at main.c:766
#7 0x081bf35a in current_interp_command_loop ()
#8 0x081bfbcf in captured_command_loop ()
#9 0x081beddc in catch_errors ()
#10 0x081c0a9a in captured_main ()
#11 0x081beddc in catch_errors ()
#12 0x081c0adc in gdb_main ()
#13 0x081c0b29 in gdb_main_entry ()
#14 0x08121590 in gdb_main_loop (argc=2, argv=0xff964014) at gdb_interface.c:76
#15 0x08090c01 in main (argc=3, argv=0xff964014) at main.c:671
here exactly I hit invalid entry.
Regards,
Oza.
________________________________
From: paawan oza <paawan1982(a)yahoo.com>
To: Dave Anderson <anderson(a)redhat.com>; "Discussion list for crash utility
usage, maintenance and development" <crash-utility(a)redhat.com>
Sent: Friday, 1 March 2013 10:58 AM
Subject: Re: [Crash-utility] timer: invalid list entry: 1
I would give some more info.
It is dual core system. (ARM)
both core are stuck at wfi (wait for interrupt)
and we observe that the timer counter has one much ahead than the comparators.
so we never get a local timer interrupt, and nobody is there to wake the cpu up.
so we observe the freeze.
Regards,
Oza.
________________________________
From: Dave Anderson <anderson(a)redhat.com>
To: paawan oza <paawan1982(a)yahoo.com>; "Discussion list for crash utility
usage, maintenance and development" <crash-utility(a)redhat.com>
Sent: Thursday, 28 February 2013 7:54 PM
Subject: Re: [Crash-utility] timer: invalid list entry: 1
----- Original Message -----
Hi,
I am getting folowing: I am unable to get whether there is memory
corruption or crash utility has problem displaying.
using crash utility version: 6.1.1
kernel version : 3.4.5+
I am getting following.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c
<delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
TVEC_BASES[1]: dc85e000
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
384 c0a42ba8 c007260c <idle_worker_timeout>
4297862 dbec0dfc c007412c <delayed_work_timer_fn>
4297897 c162c6e0 c007412c
<delayed_work_timer_fn>
4297962 dbec0ea0 c04a7cec <estimation_timer>
4297997 c162c7cc c007412c <delayed_work_timer_fn>
4300768 dcb36654 c007412c <delayed_work_timer_fn>
4309824 c0a20024 c0516718 <addrconf_verify>
4327762 dcaabf54 c0068ebc <process_timeout>
4327808 c162aea8 c007260c <idle_worker_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
Regards,
Oza.
It's impossible to answer without knowing the specifics.
It could be corruption, or perhaps the cpu 0 was
manipulating
the timer chains when the kernel panicked, or perhaps there
is some off-the-wall condition that the crash utility has
never encountered.
Dave
Dave
11:19 a.m.
New subject: timer: invalid list entry: 1
----- Original Message -----
I would give some more info.
It is dual core system. (ARM)
both core are stuck at wfi (wait for interrupt)
and we observe that the timer counter has one much ahead than the comparators.
so we never get a local timer interrupt, and nobody is there to wake the cpu up.
so we observe the freeze.
Regards,
Oza.
I don't know much about the ARM architecture, and the only sample
SMP ARM dumpfile I have on hand shows the non-panicking cpu blocked
in default_idle(). So I don't understand how "wfi" would come
into play.
What does "bt -a" show?
some more info:
I am debugging crash utility with gdb, and getting following stack trace.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
Breakpoint 2, do_list (ld=0xff961c78) at tools.c:3507
3507 error(INFO, "\ninvalid list entry: %lx\n", next);
(gdb) bt
#0 do_list (ld=0xff961c78) at tools.c:3507
#1 0x0811de03 in do_timer_list (vec_kvaddr=3699761524, size=256,
vec=0x85c9f40, option=0x0, highest=0x0, tv=0xff962ec4) at
kernel.c:6983
#2 0x0811c9d3 in dump_timer_data_tvec_bases_v2 () at kernel.c:6678
#3 0x0811afac in dump_timer_data () at kernel.c:6370
#4 0x0811af8a in cmd_timer () at kernel.c:6329
#5 0x080910a1 in exec_command () at main.c:818
#6 0x08090ec7 in main_loop () at main.c:766
#7 0x081bf35a in current_interp_command_loop ()
#8 0x081bfbcf in captured_command_loop ()
#9 0x081beddc in catch_errors ()
#10 0x081c0a9a in captured_main ()
#11 0x081beddc in catch_errors ()
#12 0x081c0adc in gdb_main ()
#13 0x081c0b29 in gdb_main_entry ()
#14 0x08121590 in gdb_main_loop (argc=2, argv=0xff964014) at gdb_interface.c:76
#15 0x08090c01 in main (argc=3, argv=0xff964014) at main.c:671
here exactly I hit invalid entry.
Right, I understand where the error message came from.
The crash utility's do_list() function is simply reporting what
it sees in the list_head-type linked list that it was following.
I have only seen these types of timer command errors in
vmcores that were generated with the "snap.so" extension
module, or when running the command on a live system.
And both of those scenarios make perfect sense because the
underlying kernel was running/modifying the timer-related
data structures while the memory was being copied.
Presuming that the crash was taken with kdump, you would
typically expect that the timer data structures would
be stable.
Dave
4:02 a.m.
New subject: timer: invalid list entry: 1
I will post the bt -a output in next mail.
as far as crashdump is concerned, this is how we take it.
basically, we just dump whole ram (flat physical RAM), and then I have modified crash
utlilty to convert ramdump (just plain ramdump) into arm elf32 format.
and so it could get recognized by any debugger as crash utility.
and it has been working great.
I have loaded so many ramdumps, and timer and any other command is working perfectly
fine.
but only this scenario it has given such thing. where I suspected timer list
corruption/crash utility problem.
Regards,
Oza.
________________________________
From: Dave Anderson <anderson(a)redhat.com>
To: paawan oza <paawan1982(a)yahoo.com>
Cc: "Discussion list for crash utility usage, maintenance and development"
<crash-utility(a)redhat.com>
Sent: Friday, 1 March 2013 10:49 PM
Subject: Re: [Crash-utility] timer: invalid list entry: 1
----- Original Message -----
I would give some more info.
It is dual core system. (ARM)
both core are stuck at wfi (wait for interrupt)
and we observe that the timer counter has one much ahead than the comparators.
so we never get a local timer interrupt, and nobody is there to wake the cpu up.
so we observe the freeze.
Regards,
Oza.
I don't know much about the ARM architecture, and the only sample
SMP ARM dumpfile I have on hand shows the non-panicking cpu blocked
in default_idle(). So I don't understand how "wfi" would come
into play.
What does "bt -a" show?
some more info:
I am debugging crash utility with gdb, and getting following stack trace.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
Breakpoint 2, do_list (ld=0xff961c78) at tools.c:3507
3507 error(INFO, "\ninvalid list entry: %lx\n", next);
(gdb) bt
#0 do_list (ld=0xff961c78) at tools.c:3507
#1 0x0811de03 in do_timer_list (vec_kvaddr=3699761524, size=256,
vec=0x85c9f40, option=0x0, highest=0x0, tv=0xff962ec4) at
kernel.c:6983
#2 0x0811c9d3 in dump_timer_data_tvec_bases_v2 () at kernel.c:6678
#3 0x0811afac in dump_timer_data () at kernel.c:6370
#4 0x0811af8a in cmd_timer () at kernel.c:6329
#5 0x080910a1 in exec_command () at main.c:818
#6 0x08090ec7 in main_loop () at main.c:766
#7 0x081bf35a in current_interp_command_loop ()
#8 0x081bfbcf in captured_command_loop ()
#9 0x081beddc in catch_errors ()
#10 0x081c0a9a in captured_main ()
#11 0x081beddc in catch_errors ()
#12 0x081c0adc in gdb_main ()
#13 0x081c0b29 in gdb_main_entry ()
#14 0x08121590 in gdb_main_loop (argc=2, argv=0xff964014) at gdb_interface.c:76
#15 0x08090c01 in main (argc=3, argv=0xff964014) at main.c:671
here exactly I hit invalid entry.
Right, I understand where the error message came from.
The crash utility's do_list() function is simply reporting what
it sees in the list_head-type linked list that it was following.
I have only seen these types of timer command errors in
vmcores that were generated with the "snap.so" extension
module, or when running the command on a live system.
And both of those scenarios make perfect sense because the
underlying kernel was running/modifying the timer-related
data structures while the memory was being copied.
Presuming that the crash was taken with kdump, you would
typically expect that the timer data structures would
be stable.
Dave
4:21 a.m.
New subject: timer: invalid list entry: 1
wfi (is wait for interrupt), in the sense we let the cpu go ino idle/dormant when he has
nothing to do.
and the thread who has been scheduled earliest, the timer would have set accordingly and
then wake the cpu up.
here we are missing both timer interrupt on both cpu.
that means that timer counter has much gone ahead, and it will never match programmed
compare values.
so its system freeze, as interrupts are not happening.
in that freeze, we have special keryboard interrupt to take task dump and other dumps.
on that ramdump which I have crash utility would show
crash> bt -a
PID: 0 TASK: c097b8b0 CPU: 0 COMMAND: "swapper/0"
bt: WARNING: cannot get stackframe for task
PID: 0 TASK: dc84ca40 CPU: 1 COMMAND: "swapper/1"
bt: WARNING: cannot get stackframe for task
and timer
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
timer: invalid list entry: 1
timer: ignoring faulty timer list at index 44 of timer array
TVEC_BASES[1]: dc85e000
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
384 c0a42ba8 c007260c <idle_worker_timeout>
4297862 dbec0dfc c007412c <delayed_work_timer_fn>
4297897 c162c6e0 c007412c <delayed_work_timer_fn>
4297962 dbec0ea0 c04a7cec <estimation_timer>
4297997 c162c7cc c007412c <delayed_work_timer_fn>
4300768 dcb36654 c007412c <delayed_work_timer_fn>
4309824 c0a20024 c0516718 <addrconf_verify>
4327762 dcaabf54 c0068ebc <process_timeout>
4327808 c162aea8 c007260c <idle_worker_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357762 dbaa3e04 c0068ebc <process_timeout>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b83fa4 c04e4244 <inet_frag_secret_rebuild>
4357888 c0b84694 c04e4244 <inet_frag_secret_rebuild>
Regards,
Oza.
________________________________
From: Dave Anderson <anderson(a)redhat.com>
To: paawan oza <paawan1982(a)yahoo.com>
Cc: "Discussion list for crash utility usage, maintenance and development"
<crash-utility(a)redhat.com>
Sent: Friday, 1 March 2013 10:49 PM
Subject: Re: [Crash-utility] timer: invalid list entry: 1
----- Original Message -----
I would give some more info.
It is dual core system. (ARM)
both core are stuck at wfi (wait for interrupt)
and we observe that the timer counter has one much ahead than the comparators.
so we never get a local timer interrupt, and nobody is there to wake the cpu up.
so we observe the freeze.
Regards,
Oza.
I don't know much about the ARM architecture, and the only sample
SMP ARM dumpfile I have on hand shows the non-panicking cpu blocked
in default_idle(). So I don't understand how "wfi" would come
into play.
What does "bt -a" show?
some more info:
I am debugging crash utility with gdb, and getting following stack trace.
crash> timer
TVEC_BASES[0]: c0a419c0
JIFFIES
4297762
EXPIRES TIMER_LIST FUNCTION
128 c1621ea8 c007260c <idle_worker_timeout>
30208 c0b81f04 c04e4244 <inet_frag_secret_rebuild>
30720 c0b7f264 c0461440 <flow_cache_new_hashrnd>
30840 dba2be04 c0068ebc <process_timeout>
38228 dbae5e04 c0068ebc <process_timeout>
11796480 c097cb64 c0010aa4 <sched_clock_poll>
4294937694 c0a6f118 c026f820 <rx_timeout_handler>
4294945658 c16238fc c007412c <delayed_work_timer_fn>
4294945667 d811be14 c0068ebc <process_timeout>
4294945700 c16237cc c007412c <delayed_work_timer_fn>
4294945700 c16236e0 c007412c <delayed_work_timer_fn>
4294946020 c0a1dcbc c007412c <delayed_work_timer_fn>
4294946029 dca8f884 c007412c <delayed_work_timer_fn>
4294946504 c0b871c4 c007412c <delayed_work_timer_fn>
4294950720 c0b81d6c c007412c <delayed_work_timer_fn>
Breakpoint 2, do_list (ld=0xff961c78) at tools.c:3507
3507 error(INFO, "\ninvalid list entry: %lx\n", next);
(gdb) bt
#0 do_list (ld=0xff961c78) at tools.c:3507
#1 0x0811de03 in do_timer_list (vec_kvaddr=3699761524, size=256,
vec=0x85c9f40, option=0x0, highest=0x0, tv=0xff962ec4) at
kernel.c:6983
#2 0x0811c9d3 in dump_timer_data_tvec_bases_v2 () at kernel.c:6678
#3 0x0811afac in dump_timer_data () at kernel.c:6370
#4 0x0811af8a in cmd_timer () at kernel.c:6329
#5 0x080910a1 in exec_command () at main.c:818
#6 0x08090ec7 in main_loop () at main.c:766
#7 0x081bf35a in current_interp_command_loop ()
#8 0x081bfbcf in captured_command_loop ()
#9 0x081beddc in catch_errors ()
#10 0x081c0a9a in captured_main ()
#11 0x081beddc in catch_errors ()
#12 0x081c0adc in gdb_main ()
#13 0x081c0b29 in gdb_main_entry ()
#14 0x08121590 in gdb_main_loop (argc=2, argv=0xff964014) at gdb_interface.c:76
#15 0x08090c01 in main (argc=3, argv=0xff964014) at main.c:671
here exactly I hit invalid entry.
Right, I understand where the error message came from.
The crash utility's do_list() function is simply reporting what
it sees in the list_head-type linked list that it was following.
I have only seen these types of timer command errors in
vmcores that were generated with the "snap.so" extension
module, or when running the command on a live system.
And both of those scenarios make perfect sense because the
underlying kernel was running/modifying the timer-related
data structures while the memory was being copied.
Presuming that the crash was taken with kdump, you would
typically expect that the timer data structures would
be stable.
Dave
4348
days inactive
4362
days old
devel@lists.crash-utility.osci.io
22 comments
3 participants
participants (3)
-
Dave Anderson -
paawan oza -
qiaonuohan