On Thu, Feb 13, 2014 at 06:00:19PM +0100, Stefan Bader wrote: > On 12.02.2014 12:54, Peter Zijlstra wrote: > > On Wed, Feb 12, 2014 at 12:09:29PM +0100, Stefan Bader wrote: > >> Something else here I run a kernel with CONFIG_PREEMPT not set and NR_CPUS > >> limited to 8 (for the 32bit kernel). So the default apic driver is used. Since > >> default_send_IPI_mask_logical is only used from there, I assume the trace you > >> got does the same. Maybe something there is wrong which would explain why we > >> only see it on 32bit hosts. > > > > Can you try with a different APIC driver to test this? > > > I don't think I can. And I think the statement about this only be used for 32bit > could be wrong. I got mislead to think so because those are only defined in > probe_32 but the 64bit counterpart isn't containing much aside that. > > Anyway, I played around with tracing a bit more. So with this change: > > if (need_resched()) { > srcu_read_unlock(&kvm->srcu, vcpu->srcu_idx); > if (need_resched() != should_resched()) { > + trace_printk("need(%i) != should(%i)\n", > + need_resched(), should_resched()); > + trace_printk("exit_reason=%u\n", > + vcpu->run->exit_reason); > + trace_printk("preempt_count=%lx\n", > + __this_cpu_read_4(__preempt_count)); > + tracing_stop(); > + printk(KERN_ERR "Stopped tracing, due to > inconsistent state.\n"); > } > + schedule(); > - cond_reschedule(); > vcpu->srcu_idx = srcu_read_lock(&kvm->srcu); > } > > I get the following (weird) output: > > Xorg-1078 [001] d... 71.270251: native_smp_send_reschedule > <-resched_task > Xorg-1078 [001] d... 71.270251: default_send_IPI_mask_logical > <-native_smp_send_reschedule > bamfdaemon-2318 [001] d... 71.270465: resched_task <-check_preempt_wakeup > bamfdaemon-2318 [001] d... 71.270539: resched_task <-check_preempt_wakeup > compiz-2365 [001] d... 71.270689: resched_task <-check_preempt_wakeup > compiz-2365 [001] d... 71.270827: resched_task <-check_preempt_wakeup > compiz-2365 [001] d... 71.270940: resched_task <-check_preempt_wakeup > qemu-system-x86-2679 [000] dn.. 71.270999: smp_reschedule_interrupt > <-reschedule_interrupt > qemu-system-x86-2679 [000] dn.. 71.270999: scheduler_ipi > <-smp_reschedule_interrupt > qemu-system-x86-2679 [000] .N.. 71.271001: kvm_arch_vcpu_ioctl_run: need(1) > != should(0) > qemu-system-x86-2679 [000] .N.. 71.271002: kvm_arch_vcpu_ioctl_run: > exit_reason=2 > qemu-system-x86-2679 [000] .N.. 71.271003: kvm_arch_vcpu_ioctl_run: > preempt_count=0 > > So am I reading this right, that the interrupt did get delivered to cpu#0 while > the thread info already had the resched flag set. So this really should have > cleared the bit in preempt_count. But while the trace info shows 'N' for some > reason should_reschedule returns false but at the same time reading the preempt > count manually shows it 0? So the assembly merges the first and second should_resched(), so its possible that load got before the interrupt(). The 3rd preempt_count load gets re-issued and so that would show the 'true' value again. If you want to force a reload after the condition; put in a barrier(). In any case; this looks like a false-positive. Please try again until you get one where the interrupt doesn't happen and we stay in 'n' state. -- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html