Marcelo Tosatti wrote:
> On Thu, Jan 15, 2009 at 03:20:06PM +0800, Sheng Yang wrote:
>
>>> + * Since reinjection is not rate-limited, use the delay
>>> + * to inject the last interrupt as an estimate.
>>> + */
>>> + if (unlikely(atomic_read(&apic->timer.pending) > 0)) {
>>> + remaining = apic->timer.injection_delay;
>>> + if (ktime_to_ns(remaining) > apic->timer.period)
>>> + remaining = ns_to_ktime(apic->timer.period);
>>> + } else
>>> + remaining = hrtimer_expires_remaining(&apic->timer.dev);
>>>
>> A little doubt...
>>
>> A: time_fire
>> B: intr_post
>> C: read TMCCT
>>
>> The sequence can be ABC or ACB.
>>
>> injection_delay = time(B) - time(A)
>>
>> So it didn't count time from read TMCCT... And guest get interrupt at
>> time(B),
>> not quite understand why time(B) - time(A) matters here...
>>
>
> Its an estimate of the delay it takes to inject an interrupt to the
> guest once fired. Its only used if there have been accumulated ones, so
> ACB sequence with pending=0 will use hrtimer_expires_remaining().
>
>
>> I think the reasonable here means, this interval is usable later after the
>> accumulated interrupts are injected. From this point of view, I think
>> current
>> solution is reasonable. It just assume the delayed interrupts have been
>> injected.
>>
>> However, seriously, any value here is wrong, no elegant one.
>>
>
> I agree.
>
>
>> But I still prefer to the current solution...
>>
>
> Why? The proposed version is smaller and simpler than the current
> one IMO, and also not vulnerable to whatever bug is causing now <
> last_update.
>
> And more precise, since the current scheme uses interrupt injection time
> as if it was "count-down restart" time, which is not true.
>
>
>> And here is not the really problem for now I think. The current mechanism is
>> mostly OK, but where is the bug... We have either have a simple fix(e.g. if
>> now < last_update, then return 0) or dig into it. Did it worth a try?
>> Anyway,
>> it would return a buggy result if we have pending interrupts...
>>
>
> The overflow calculation is not necessary as discussed. Alexander, can
> you please try the following? Sheng, do you have any other suggestion to
> test?
>
> /proc/timer_list output of the host when ESX is running too.
>
Sorry for the late reply. Here's the dmesg output and /proc/timer_list
after the issue occured. I left the warning message in that I put there
in case the value is too high:
counter_passed = div64_u64(ktime_to_ns(passed),
(APIC_BUS_CYCLE_NS *
apic->timer.divide_count));
+ if (counter_passed > 0x7f00000000000000) {
+ /* If we're in here we probably encountered a bug! */
+ printk(KERN_INFO "LAPIC: Too high counter_passed value:
0x%lx | 0x%lx (0x%lx) | 0x%lx (0x%lx)\n", counter_passed,
ktime_to_ns(passed), passed, now.tv64, apic
->timer.last_update.tv64);
+ }
+
if (counter_passed > tmcct) {
if (unlikely(!apic_lvtt_period(apic))) {
/* one-shot timers stick at 0 until reset */
start_apic_timer: bus cycle is 1ns, now 0x00039a6f377cfbc4, timer
initial count 0x186a0, period 100000ns, expire @ 0x00039a6f377e8264.
start_apic_timer: bus cycle is 1ns, now 0x00039a6f3a7b5aef, timer
initial count 0x203a0, period 132000ns, expire @ 0x00039a6f3a7d5e8f.
last_update = 1014860818546063 now = 1014860818426085
rec[47] when=1014860811948512 last_update=1014860812078063 pend=0
rec[46] when=1014860818417773 last_update=1014860818546063 pend=0
rec[45] when=1014860818285454 last_update=1014860818414063 pend=0
rec[44] when=1014860818153119 last_update=1014860818282063 pend=0
rec[43] when=1014860818021746 last_update=1014860818150063 pend=0
rec[42] when=1014860817889326 last_update=1014860818018063 pend=0
rec[41] when=1014860817757297 last_update=1014860817886063 pend=0
rec[40] when=1014860817625682 last_update=1014860817754063 pend=0
rec[39] when=1014860817492484 last_update=1014860817622063 pend=0
rec[38] when=1014860817360531 last_update=1014860817490063 pend=0
rec[37] when=1014860817228489 last_update=1014860817358063 pend=0
rec[36] when=1014860817101250 last_update=1014860817226063 pend=0
rec[35] when=1014860816964378 last_update=1014860817094063 pend=0
rec[34] when=1014860816832459 last_update=1014860816962063 pend=0
rec[33] when=1014860816700514 last_update=1014860816830063 pend=0
rec[32] when=1014860816568558 last_update=1014860816698063 pend=0
rec[31] when=1014860816436510 last_update=1014860816566063 pend=0
rec[30] when=1014860816305079 last_update=1014860816434063 pend=0
rec[29] when=1014860816172560 last_update=1014860816302063 pend=0
rec[28] when=1014860816040449 last_update=1014860816170063 pend=0
rec[27] when=1014860815908500 last_update=1014860816038063 pend=0
rec[26] when=1014860815776451 last_update=1014860815906063 pend=0
rec[25] when=1014860815644499 last_update=1014860815774063 pend=0
rec[24] when=1014860815513100 last_update=1014860815642063 pend=0
rec[23] when=1014860815380476 last_update=1014860815510063 pend=0
rec[22] when=1014860815248609 last_update=1014860815378063 pend=0
rec[21] when=1014860815116494 last_update=1014860815246063 pend=0
rec[20] when=1014860814984441 last_update=1014860815114063 pend=0
rec[19] when=1014860814852498 last_update=1014860814982063 pend=0
rec[18] when=1014860814721082 last_update=1014860814850063 pend=0
rec[17] when=1014860814588467 last_update=1014860814718063 pend=0
rec[16] when=1014860814456530 last_update=1014860814586063 pend=0
rec[15] when=1014860814324452 last_update=1014860814454063 pend=0
rec[14] when=1014860814192601 last_update=1014860814322063 pend=0
rec[13] when=1014860814060489 last_update=1014860814190063 pend=0
rec[12] when=1014860813928546 last_update=1014860814058063 pend=0
rec[11] when=1014860813797571 last_update=1014860813926063 pend=0
rec[10] when=1014860813664475 last_update=1014860813794063 pend=0
rec[9] when=1014860813532520 last_update=1014860813662063 pend=0
rec[8] when=1014860813400463 last_update=1014860813530063 pend=0
rec[7] when=1014860813268519 last_update=1014860813398063 pend=0
rec[6] when=1014860813136452 last_update=1014860813266063 pend=0
rec[5] when=1014860813007312 last_update=1014860813134063 pend=0
rec[4] when=1014860812872314 last_update=1014860813002063 pend=0
rec[3] when=1014860812740791 last_update=1014860812870063 pend=0
rec[2] when=1014860812652998 last_update=1014860812738063 pend=0
rec[1] when=1014860812476526 last_update=1014860812606063 pend=0
rec[0] when=1014860812344635 last_update=1014860812474063 pend=0
rec[49] when=1014860812213098 last_update=1014860812342063 pend=0
rec[48] when=1014860812080466 last_update=1014860812210063 pend=0
LAPIC: Too high counter_passed value: 0x7ffffffffffe2b55 |
0x7ffffffffffe2b55 (0x7ffffffffffe2b55) | 0x39b02b29428e5 (0x39b02b295fd8f)
start_apic_timer: bus cycle is 1ns, now 0x00039b02b2998ada, timer
initial count 0x8400, period 33792ns, expire @ 0x00039b02b29a0eda.
ag...@busu:~/git/kvm-userspace/patch-virtio> cat /proc/timer_list
Timer List Version: v0.3
HRTIMER_MAX_CLOCK_BASES: 2
now at 1015003705479836 nsecs
cpu: 0
clock 0:
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1231432907192509789 nsecs
active timers:
clock 1:
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff88005c0a9d68>, tick_sched_timer, S:01,
tick_nohz_restart_sched_tick, swapper/0
# expires at 1015003708000000 nsecs [in 2520164 nsecs]
#1: <ffff88005c0a9d68>, posix_timer_fn, S:01, common_timer_set,
qemu-system-x86/12319
# expires at 1015003730134958 nsecs [in 24655122 nsecs]
#2: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/16571
# expires at 1015004228913679 nsecs [in 523433843 nsecs]
#3: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/5575
# expires at 1015004235164609 nsecs [in 529684773 nsecs]
#4: <ffff88005c0a9d68>, it_real_fn, S:01, do_setitimer, ntpd/3897
# expires at 1015004515252084 nsecs [in 809772248 nsecs]
#5: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, mono/4506
# expires at 1015007076193303 nsecs [in 3370713467 nsecs]
#6: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/5568
# expires at 1015011817382709 nsecs [in 8111902873 nsecs]
#7: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, ypbind/3441
# expires at 1015018457521563 nsecs [in 14752041727 nsecs]
#8: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, cron/4093
# expires at 1015033940939337 nsecs [in 30235459501 nsecs]
#9: <ffff88005c0a9d68>, it_real_fn, S:01, do_setitimer, qmgr/4085
# expires at 1015280112163402 nsecs [in 276406683566 nsecs]
#10: <ffff88005c0a9d68>, it_real_fn, S:01, do_setitimer, pickup/10231
# expires at 1015285116223756 nsecs [in 281410743920 nsecs]
#11: <ffff88005c0a9d68>, it_real_fn, S:01, do_setitimer, master/4058
# expires at 1015285116254144 nsecs [in 281410774308 nsecs]
.expires_next : 1015003708000000 nsecs
.hres_active : 1
.nr_events : 580379958
.nohz_mode : 2
.idle_tick : 1015003700000000 nsecs
.tick_stopped : 0
.idle_jiffies : 4548643220
.idle_calls : 593550517
.idle_sleeps : 362170032
.idle_entrytime : 1015003701647385 nsecs
.idle_waketime : 1015003701630992 nsecs
.idle_exittime : 1015003702532497 nsecs
.idle_sleeptime : 571458026968578 nsecs
.last_jiffies : 4548643221
.next_jiffies : 4548643224
.idle_expires : 1015003712000000 nsecs
jiffies: 4548643222
cpu: 1
clock 0:
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1231432907192509789 nsecs
active timers:
clock 1:
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait, beagled/4716
# expires at 1015003708490644 nsecs [in 3010808 nsecs]
#1: <ffff88005c0a9d68>, tick_sched_timer, S:01,
tick_nohz_restart_sched_tick, swapper/0
# expires at 1015003708500000 nsecs [in 3020164 nsecs]
#2: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep,
xosview.bin/9582
# expires at 1015003726118330 nsecs [in 20638494 nsecs]
#3: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait, beagled/4718
# expires at 1015003794490837 nsecs [in 89011001 nsecs]
#4: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait, automount/3918
# expires at 1015003984221642 nsecs [in 278741806 nsecs]
#5: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/9982
# expires at 1015004091979648 nsecs [in 386499812 nsecs]
#6: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep,
beagled-helper/10041
# expires at 1015004496780704 nsecs [in 791300868 nsecs]
#7: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, mono/10031
# expires at 1015004573838387 nsecs [in 868358551 nsecs]
#8: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, mono/4568
# expires at 1015007037900538 nsecs [in 3332420702 nsecs]
#9: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, irqbalance/3631
# expires at 1015010807493897 nsecs [in 7102014061 nsecs]
#10: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/12567
# expires at 1015052672245807 nsecs [in 48966765971 nsecs]
#11: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep, smartd/4119
# expires at 1015236365925605 nsecs [in 232660445769 nsecs]
.expires_next : 1015003708490644 nsecs
.hres_active : 1
.nr_events : 1177733430
.nohz_mode : 2
.idle_tick : 1015003704500000 nsecs
.tick_stopped : 0
.idle_jiffies : 4548643221
.idle_calls : 1078408244
.idle_sleeps : 846829238
.idle_entrytime : 1015003704530991 nsecs
.idle_waketime : 1015003698212870 nsecs
.idle_exittime : 1015003701647606 nsecs
.idle_sleeptime : 775344327548400 nsecs
.last_jiffies : 4548643221
.next_jiffies : 4548643247
.idle_expires : 1015003804000000 nsecs
jiffies: 4548643222
cpu: 2
clock 0:
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1231432907192509789 nsecs
active timers:
clock 1:
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff88005c0a9d68>, apic_timer_fn, S:01, start_apic_timer,
qemu-system-x86/12327
# expires at 1015003705716442 nsecs [in 236606 nsecs]
#1: <ffff88005c0a9d68>, tick_sched_timer, S:01,
tick_nohz_restart_sched_tick, swapper/0
# expires at 1015003709000000 nsecs [in 3520164 nsecs]
#2: <ffff88005c0a9d68>, pit_timer_fn, S:01, pit_ioport_write,
qemu-system-x86/12327
# expires at 1015003712306931 nsecs [in 6827095 nsecs]
#3: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait, firefox/19140
# expires at 1015003723685421 nsecs [in 18205585 nsecs]
#4: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait, automount/3919
# expires at 1015003987442435 nsecs [in 281962599 nsecs]
#5: <ffff88005c0a9d68>, it_real_fn, S:01, do_setitimer, screen/14384
# expires at 1015005458349005 nsecs [in 1752869169 nsecs]
.expires_next : 1015003705817818 nsecs
.hres_active : 1
.nr_events : 523400970
.nohz_mode : 2
.idle_tick : 1014859089000000 nsecs
.tick_stopped : 0
.idle_jiffies : 4548607067
.idle_calls : 336510407
.idle_sleeps : 258867154
.idle_entrytime : 1014859085481448 nsecs
.idle_waketime : 1014859053575960 nsecs
.idle_exittime : 1014859085485692 nsecs
.idle_sleeptime : 395655240495416 nsecs
.last_jiffies : 4548607067
.next_jiffies : 4548607171
.idle_expires : 1014859500000000 nsecs
jiffies: 4548643222
cpu: 3
clock 0:
.index: 0
.resolution: 1 nsecs
.get_time: ktime_get_real
.offset: 1231432907192509789 nsecs
active timers:
clock 1:
.index: 1
.resolution: 1 nsecs
.get_time: ktime_get
.offset: 0 nsecs
active timers:
#0: <ffff88005c0a9d68>, tick_sched_timer, S:01,
tick_nohz_restart_sched_tick, swapper/0
# expires at 1015003709500000 nsecs [in 4020164 nsecs]
#1: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, do_nanosleep,
xosview.bin/1922
# expires at 1015003770033068 nsecs [in 64553232 nsecs]
#2: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/7131
# expires at 1015003800127636 nsecs [in 94647800 nsecs]
#3: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/10001
# expires at 1015003962537676 nsecs [in 257057840 nsecs]
#4: <ffff88005c0a9d68>, sched_rt_period_timer, S:01,
__enqueue_rt_entity, swapper/1
# expires at 1015004000000000 nsecs [in 294520164 nsecs]
#5: <ffff88005c0a9d68>, hrtimer_wakeup, S:01, futex_wait,
thunderbird-bin/5577
# expires at 1015004228745798 nsecs [in 523265962 nsecs]
.expires_next : 1015003709500000 nsecs
.hres_active : 1
.nr_events : 1260974322
.nohz_mode : 2
.idle_tick : 1015003381500000 nsecs
.tick_stopped : 0
.idle_jiffies : 4548643141
.idle_calls : 1146068541
.idle_sleeps : 910709854
.idle_entrytime : 1015003705511942 nsecs
.idle_waketime : 1015003380002663 nsecs
.idle_exittime : 1015003408508278 nsecs
.idle_sleeptime : 782489673980131 nsecs
.last_jiffies : 4548643222
.next_jiffies : 4548643241
.idle_expires : 1015003660000000 nsecs
jiffies: 4548643222
Tick Device: mode: 1
Clock Event Device: hpet
max_delta_ns: 85899346200
min_delta_ns: 5000
mult: 107374182
shift: 32
mode: 3
next_event: 9223372036854775807 nsecs
set_next_event: hpet_legacy_next_event
set_mode: hpet_legacy_set_mode
event_handler: tick_handle_oneshot_broadcast
tick_broadcast_mask: 00000000
tick_broadcast_oneshot_mask: 00000000
Tick Device: mode: 1
Clock Event Device: lapic
max_delta_ns: 669608197
min_delta_ns: 1197
mult: 53805782
shift: 32
mode: 3
next_event: 1015003708000000 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
Tick Device: mode: 1
Clock Event Device: lapic
max_delta_ns: 669608197
min_delta_ns: 1197
mult: 53805782
shift: 32
mode: 3
next_event: 1015003708490644 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
Tick Device: mode: 1
Clock Event Device: lapic
max_delta_ns: 669608197
min_delta_ns: 1197
mult: 53805782
shift: 32
mode: 3
next_event: 1015003705919194 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
Tick Device: mode: 1
Clock Event Device: lapic
max_delta_ns: 669608197
min_delta_ns: 1197
mult: 53805782
shift: 32
mode: 3
next_event: 1015003709500000 nsecs
set_next_event: lapic_next_event
set_mode: lapic_timer_setup
event_handler: hrtimer_interrupt
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
