KVM: s390: Fixup interrupt vcpu event messages and levels
This reworks the debug logging for interrupt related logs. Several changes: - unify program int/irq - improve decoding (e.g. use mcic instead of parm64 for machine check injection) - remove useless interrupt type number (the name is enough) - rename "interrupt:" to "deliver:" as the other side is called "inject" - use log level 3 for state changing and/or seldom events (like machine checks, restart..) - use log level 4 for frequent events - use 0x prefix for hex numbers - add pfault done logging - move some tracing outside spinlock Signed-off-by: Christian Borntraeger <borntraeger@de.ibm.com> Reviewed-by: Cornelia Huck <cornelia.huck@de.ibm.com> Reviewed-by: Jens Freimann <jfrei@linux.vnet.ibm.com>
This commit is contained in:
parent
ab7090a611
commit
3f24ba150c
@ -311,8 +311,8 @@ static int __must_check __deliver_pfault_init(struct kvm_vcpu *vcpu)
|
|||||||
li->irq.ext.ext_params2 = 0;
|
li->irq.ext.ext_params2 = 0;
|
||||||
spin_unlock(&li->lock);
|
spin_unlock(&li->lock);
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "interrupt: pfault init parm:%x,parm64:%llx",
|
VCPU_EVENT(vcpu, 4, "deliver: pfault init token 0x%llx",
|
||||||
0, ext.ext_params2);
|
ext.ext_params2);
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
KVM_S390_INT_PFAULT_INIT,
|
KVM_S390_INT_PFAULT_INIT,
|
||||||
0, ext.ext_params2);
|
0, ext.ext_params2);
|
||||||
@ -368,7 +368,7 @@ static int __must_check __deliver_machine_check(struct kvm_vcpu *vcpu)
|
|||||||
spin_unlock(&fi->lock);
|
spin_unlock(&fi->lock);
|
||||||
|
|
||||||
if (deliver) {
|
if (deliver) {
|
||||||
VCPU_EVENT(vcpu, 4, "interrupt: machine check mcic=%llx",
|
VCPU_EVENT(vcpu, 3, "deliver: machine check mcic 0x%llx",
|
||||||
mchk.mcic);
|
mchk.mcic);
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
KVM_S390_MCHK,
|
KVM_S390_MCHK,
|
||||||
@ -403,7 +403,7 @@ static int __must_check __deliver_restart(struct kvm_vcpu *vcpu)
|
|||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
int rc;
|
int rc;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "%s", "interrupt: cpu restart");
|
VCPU_EVENT(vcpu, 3, "%s", "deliver: cpu restart");
|
||||||
vcpu->stat.deliver_restart_signal++;
|
vcpu->stat.deliver_restart_signal++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_RESTART, 0, 0);
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_RESTART, 0, 0);
|
||||||
|
|
||||||
@ -449,7 +449,7 @@ static int __must_check __deliver_emergency_signal(struct kvm_vcpu *vcpu)
|
|||||||
clear_bit(IRQ_PEND_EXT_EMERGENCY, &li->pending_irqs);
|
clear_bit(IRQ_PEND_EXT_EMERGENCY, &li->pending_irqs);
|
||||||
spin_unlock(&li->lock);
|
spin_unlock(&li->lock);
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "%s", "interrupt: sigp emerg");
|
VCPU_EVENT(vcpu, 4, "%s", "deliver: sigp emerg");
|
||||||
vcpu->stat.deliver_emergency_signal++;
|
vcpu->stat.deliver_emergency_signal++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_INT_EMERGENCY,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_INT_EMERGENCY,
|
||||||
cpu_addr, 0);
|
cpu_addr, 0);
|
||||||
@ -476,7 +476,7 @@ static int __must_check __deliver_external_call(struct kvm_vcpu *vcpu)
|
|||||||
clear_bit(IRQ_PEND_EXT_EXTERNAL, &li->pending_irqs);
|
clear_bit(IRQ_PEND_EXT_EXTERNAL, &li->pending_irqs);
|
||||||
spin_unlock(&li->lock);
|
spin_unlock(&li->lock);
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "%s", "interrupt: sigp ext call");
|
VCPU_EVENT(vcpu, 4, "%s", "deliver: sigp ext call");
|
||||||
vcpu->stat.deliver_external_call++;
|
vcpu->stat.deliver_external_call++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
KVM_S390_INT_EXTERNAL_CALL,
|
KVM_S390_INT_EXTERNAL_CALL,
|
||||||
@ -505,7 +505,7 @@ static int __must_check __deliver_prog(struct kvm_vcpu *vcpu)
|
|||||||
memset(&li->irq.pgm, 0, sizeof(pgm_info));
|
memset(&li->irq.pgm, 0, sizeof(pgm_info));
|
||||||
spin_unlock(&li->lock);
|
spin_unlock(&li->lock);
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "interrupt: pgm check code:%x, ilc:%x",
|
VCPU_EVENT(vcpu, 3, "deliver: program irq code 0x%x, ilc:%d",
|
||||||
pgm_info.code, ilc);
|
pgm_info.code, ilc);
|
||||||
vcpu->stat.deliver_program_int++;
|
vcpu->stat.deliver_program_int++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_PROGRAM_INT,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_PROGRAM_INT,
|
||||||
@ -621,7 +621,7 @@ static int __must_check __deliver_service(struct kvm_vcpu *vcpu)
|
|||||||
clear_bit(IRQ_PEND_EXT_SERVICE, &fi->pending_irqs);
|
clear_bit(IRQ_PEND_EXT_SERVICE, &fi->pending_irqs);
|
||||||
spin_unlock(&fi->lock);
|
spin_unlock(&fi->lock);
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 4, "interrupt: sclp parm:%x",
|
VCPU_EVENT(vcpu, 4, "deliver: sclp parameter 0x%x",
|
||||||
ext.ext_params);
|
ext.ext_params);
|
||||||
vcpu->stat.deliver_service_signal++;
|
vcpu->stat.deliver_service_signal++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_INT_SERVICE,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id, KVM_S390_INT_SERVICE,
|
||||||
@ -650,9 +650,6 @@ static int __must_check __deliver_pfault_done(struct kvm_vcpu *vcpu)
|
|||||||
struct kvm_s390_interrupt_info,
|
struct kvm_s390_interrupt_info,
|
||||||
list);
|
list);
|
||||||
if (inti) {
|
if (inti) {
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
|
||||||
KVM_S390_INT_PFAULT_DONE, 0,
|
|
||||||
inti->ext.ext_params2);
|
|
||||||
list_del(&inti->list);
|
list_del(&inti->list);
|
||||||
fi->counters[FIRQ_CNTR_PFAULT] -= 1;
|
fi->counters[FIRQ_CNTR_PFAULT] -= 1;
|
||||||
}
|
}
|
||||||
@ -661,6 +658,12 @@ static int __must_check __deliver_pfault_done(struct kvm_vcpu *vcpu)
|
|||||||
spin_unlock(&fi->lock);
|
spin_unlock(&fi->lock);
|
||||||
|
|
||||||
if (inti) {
|
if (inti) {
|
||||||
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
|
KVM_S390_INT_PFAULT_DONE, 0,
|
||||||
|
inti->ext.ext_params2);
|
||||||
|
VCPU_EVENT(vcpu, 4, "deliver: pfault done token 0x%llx",
|
||||||
|
inti->ext.ext_params2);
|
||||||
|
|
||||||
rc = put_guest_lc(vcpu, EXT_IRQ_CP_SERVICE,
|
rc = put_guest_lc(vcpu, EXT_IRQ_CP_SERVICE,
|
||||||
(u16 *)__LC_EXT_INT_CODE);
|
(u16 *)__LC_EXT_INT_CODE);
|
||||||
rc |= put_guest_lc(vcpu, PFAULT_DONE,
|
rc |= put_guest_lc(vcpu, PFAULT_DONE,
|
||||||
@ -690,7 +693,7 @@ static int __must_check __deliver_virtio(struct kvm_vcpu *vcpu)
|
|||||||
list);
|
list);
|
||||||
if (inti) {
|
if (inti) {
|
||||||
VCPU_EVENT(vcpu, 4,
|
VCPU_EVENT(vcpu, 4,
|
||||||
"interrupt: virtio parm:%x,parm64:%llx",
|
"deliver: virtio parm: 0x%x,parm64: 0x%llx",
|
||||||
inti->ext.ext_params, inti->ext.ext_params2);
|
inti->ext.ext_params, inti->ext.ext_params2);
|
||||||
vcpu->stat.deliver_virtio_interrupt++;
|
vcpu->stat.deliver_virtio_interrupt++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
@ -740,7 +743,7 @@ static int __must_check __deliver_io(struct kvm_vcpu *vcpu,
|
|||||||
struct kvm_s390_interrupt_info,
|
struct kvm_s390_interrupt_info,
|
||||||
list);
|
list);
|
||||||
if (inti) {
|
if (inti) {
|
||||||
VCPU_EVENT(vcpu, 4, "interrupt: I/O %llx", inti->type);
|
VCPU_EVENT(vcpu, 4, "deliver: I/O 0x%llx", inti->type);
|
||||||
vcpu->stat.deliver_io_int++;
|
vcpu->stat.deliver_io_int++;
|
||||||
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
trace_kvm_s390_deliver_interrupt(vcpu->vcpu_id,
|
||||||
inti->type,
|
inti->type,
|
||||||
@ -863,7 +866,7 @@ int kvm_s390_handle_wait(struct kvm_vcpu *vcpu)
|
|||||||
|
|
||||||
__set_cpu_idle(vcpu);
|
__set_cpu_idle(vcpu);
|
||||||
hrtimer_start(&vcpu->arch.ckc_timer, ktime_set (0, sltime) , HRTIMER_MODE_REL);
|
hrtimer_start(&vcpu->arch.ckc_timer, ktime_set (0, sltime) , HRTIMER_MODE_REL);
|
||||||
VCPU_EVENT(vcpu, 5, "enabled wait via clock comparator: %llx ns", sltime);
|
VCPU_EVENT(vcpu, 4, "enabled wait via clock comparator: %llu ns", sltime);
|
||||||
no_timer:
|
no_timer:
|
||||||
srcu_read_unlock(&vcpu->kvm->srcu, vcpu->srcu_idx);
|
srcu_read_unlock(&vcpu->kvm->srcu, vcpu->srcu_idx);
|
||||||
kvm_vcpu_block(vcpu);
|
kvm_vcpu_block(vcpu);
|
||||||
@ -1008,8 +1011,8 @@ static int __inject_pfault_init(struct kvm_vcpu *vcpu, struct kvm_s390_irq *irq)
|
|||||||
{
|
{
|
||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: external irq params:%x, params2:%llx",
|
VCPU_EVENT(vcpu, 4, "inject: pfault init parameter block at 0x%llx",
|
||||||
irq->u.ext.ext_params, irq->u.ext.ext_params2);
|
irq->u.ext.ext_params2);
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_PFAULT_INIT,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_PFAULT_INIT,
|
||||||
irq->u.ext.ext_params,
|
irq->u.ext.ext_params,
|
||||||
irq->u.ext.ext_params2);
|
irq->u.ext.ext_params2);
|
||||||
@ -1041,7 +1044,7 @@ static int __inject_extcall(struct kvm_vcpu *vcpu, struct kvm_s390_irq *irq)
|
|||||||
struct kvm_s390_extcall_info *extcall = &li->irq.extcall;
|
struct kvm_s390_extcall_info *extcall = &li->irq.extcall;
|
||||||
uint16_t src_id = irq->u.extcall.code;
|
uint16_t src_id = irq->u.extcall.code;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: external call source-cpu:%u",
|
VCPU_EVENT(vcpu, 4, "inject: external call source-cpu:%u",
|
||||||
src_id);
|
src_id);
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_EXTERNAL_CALL,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_EXTERNAL_CALL,
|
||||||
src_id, 0);
|
src_id, 0);
|
||||||
@ -1110,7 +1113,7 @@ static int __inject_sigp_restart(struct kvm_vcpu *vcpu,
|
|||||||
{
|
{
|
||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: restart type %llx", irq->type);
|
VCPU_EVENT(vcpu, 3, "%s", "inject: restart int");
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_RESTART, 0, 0);
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_RESTART, 0, 0);
|
||||||
|
|
||||||
set_bit(IRQ_PEND_RESTART, &li->pending_irqs);
|
set_bit(IRQ_PEND_RESTART, &li->pending_irqs);
|
||||||
@ -1122,7 +1125,7 @@ static int __inject_sigp_emergency(struct kvm_vcpu *vcpu,
|
|||||||
{
|
{
|
||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: emergency %u\n",
|
VCPU_EVENT(vcpu, 4, "inject: emergency from cpu %u",
|
||||||
irq->u.emerg.code);
|
irq->u.emerg.code);
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_EMERGENCY,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_EMERGENCY,
|
||||||
irq->u.emerg.code, 0);
|
irq->u.emerg.code, 0);
|
||||||
@ -1138,7 +1141,7 @@ static int __inject_mchk(struct kvm_vcpu *vcpu, struct kvm_s390_irq *irq)
|
|||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
struct kvm_s390_mchk_info *mchk = &li->irq.mchk;
|
struct kvm_s390_mchk_info *mchk = &li->irq.mchk;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 5, "inject: machine check parm64:%llx",
|
VCPU_EVENT(vcpu, 3, "inject: machine check mcic 0x%llx",
|
||||||
irq->u.mchk.mcic);
|
irq->u.mchk.mcic);
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_MCHK, 0,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_MCHK, 0,
|
||||||
irq->u.mchk.mcic);
|
irq->u.mchk.mcic);
|
||||||
@ -1168,7 +1171,7 @@ static int __inject_ckc(struct kvm_vcpu *vcpu)
|
|||||||
{
|
{
|
||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: type %x", KVM_S390_INT_CLOCK_COMP);
|
VCPU_EVENT(vcpu, 3, "%s", "inject: clock comparator external");
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_CLOCK_COMP,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_CLOCK_COMP,
|
||||||
0, 0);
|
0, 0);
|
||||||
|
|
||||||
@ -1181,7 +1184,7 @@ static int __inject_cpu_timer(struct kvm_vcpu *vcpu)
|
|||||||
{
|
{
|
||||||
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
struct kvm_s390_local_interrupt *li = &vcpu->arch.local_int;
|
||||||
|
|
||||||
VCPU_EVENT(vcpu, 3, "inject: type %x", KVM_S390_INT_CPU_TIMER);
|
VCPU_EVENT(vcpu, 3, "%s", "inject: cpu timer external");
|
||||||
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_CPU_TIMER,
|
trace_kvm_s390_inject_vcpu(vcpu->vcpu_id, KVM_S390_INT_CPU_TIMER,
|
||||||
0, 0);
|
0, 0);
|
||||||
|
|
||||||
@ -1431,14 +1434,14 @@ int kvm_s390_inject_vm(struct kvm *kvm,
|
|||||||
inti->ext.ext_params2 = s390int->parm64;
|
inti->ext.ext_params2 = s390int->parm64;
|
||||||
break;
|
break;
|
||||||
case KVM_S390_INT_SERVICE:
|
case KVM_S390_INT_SERVICE:
|
||||||
VM_EVENT(kvm, 5, "inject: sclp parm:%x", s390int->parm);
|
VM_EVENT(kvm, 4, "inject: sclp parm:%x", s390int->parm);
|
||||||
inti->ext.ext_params = s390int->parm;
|
inti->ext.ext_params = s390int->parm;
|
||||||
break;
|
break;
|
||||||
case KVM_S390_INT_PFAULT_DONE:
|
case KVM_S390_INT_PFAULT_DONE:
|
||||||
inti->ext.ext_params2 = s390int->parm64;
|
inti->ext.ext_params2 = s390int->parm64;
|
||||||
break;
|
break;
|
||||||
case KVM_S390_MCHK:
|
case KVM_S390_MCHK:
|
||||||
VM_EVENT(kvm, 5, "inject: machine check parm64:%llx",
|
VM_EVENT(kvm, 3, "inject: machine check mcic 0x%llx",
|
||||||
s390int->parm64);
|
s390int->parm64);
|
||||||
inti->mchk.cr14 = s390int->parm; /* upper bits are not used */
|
inti->mchk.cr14 = s390int->parm; /* upper bits are not used */
|
||||||
inti->mchk.mcic = s390int->parm64;
|
inti->mchk.mcic = s390int->parm64;
|
||||||
|
Loading…
Reference in New Issue
Block a user