linux-kernel - [KVM timekeeping 35/35] Add some debug stuff

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [day] [month] [year] [list]

Message-Id: <1282291669-25709-36-git-send-email-zamsden@redhat.com>
Date:	Thu, 19 Aug 2010 22:07:49 -1000
From:	Zachary Amsden <zamsden@...hat.com>
To:	kvm@...r.kernel.org
Cc:	Zachary Amsden <zamsden@...hat.com>, Avi Kivity <avi@...hat.com>,
	Marcelo Tosatti <mtosatti@...hat.com>,
	Glauber Costa <glommer@...hat.com>,
	Thomas Gleixner <tglx@...utronix.de>,
	John Stultz <johnstul@...ibm.com>, linux-kernel@...r.kernel.org
Subject: [KVM timekeeping 35/35] Add some debug stuff

Very useful, debug-only output

Signed-off-by: Zachary Amsden <zamsden@...hat.com>
---
 arch/x86/kvm/x86.c |   33 +++++++++++++++++++++++++++++++--
 1 files changed, 31 insertions(+), 2 deletions(-)

diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index 23d5138..c74a087 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -967,6 +967,9 @@ static void bump_guest_tsc(struct kvm_vcpu *vcpu, s64 bump, s64 kernel_ns)
 	pr_debug("kvm: vcpu%d bumped TSC by %lld\n", vcpu->vcpu_id, bump);
 }
 
+static int tsc_read_log;
+static int tsc_read_cpu = -1;
+
 void kvm_write_tsc(struct kvm_vcpu *vcpu, u64 data)
 {
 	struct kvm *kvm = vcpu->kvm;
@@ -983,6 +986,12 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, u64 data)
 	if (sdiff < 0)
 		sdiff = -sdiff;
 
+#ifdef DEBUG
+	pr_debug("kvm: tsc%d write %llu (ofs %llu)\n", vcpu->vcpu_id, data,
+		 offset);
+	tsc_read_log += 2;
+#endif
+
 	/*
 	 * Special case: TSC write with a small delta of virtual
 	 * cycle time against real time is interpreted as an attempt
@@ -999,7 +1008,8 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, u64 data)
 	if (sdiff < nsec_to_cycles(kvm, NSEC_PER_SEC) ) {
 		if (!check_tsc_unstable()) {
 			offset = kvm->arch.last_tsc_offset;
-			pr_debug("kvm: matched tsc offset for %llu\n", data);
+			pr_debug("kvm: matched tsc%d offset for %llu\n", 
+				 vcpu->vcpu_id, data);
 		} else {
 			/* Unstable write; allow offset, preserve last write */
 			pr_debug("kvm: matched write on unstable tsc\n");
@@ -1029,6 +1039,16 @@ void kvm_read_tsc(struct kvm_vcpu *vcpu)
 	kvm_register_write(vcpu, VCPU_REGS_RDX, tsc >> 32);
 	vcpu->arch.last_guest_tsc = tsc;
 	kvm_x86_ops->skip_emulated_instruction(vcpu);
+
+#ifdef DEBUG
+	if (tsc_read_log > 0 && vcpu->vcpu_id != tsc_read_cpu) {
+		--tsc_read_log;
+		tsc_read_cpu = vcpu->vcpu_id;
+		pr_debug("kvm_read_tsc: cpu%d [TRAP] %llu\n",vcpu->vcpu_id,tsc);
+		kvm_get_msr(vcpu, MSR_IA32_TSC, &tsc);
+		pr_debug("kvm_read_tsc: cpu%d [PASS] %llu\n",vcpu->vcpu_id,tsc);
+	}
+#endif
 }
 EXPORT_SYMBOL_GPL(kvm_read_tsc);
 
@@ -1070,11 +1090,16 @@ static int kvm_guest_time_update(struct kvm_vcpu *v)
 		 */
 		if (unlikely(vcpu->tsc_overrun)) {
 			vcpu->tsc_overrun = 0;
-			if (vcpu->last_guest_tsc)
+			if (vcpu->last_guest_tsc) {
+				pr_debug("kvm: corrected TSC overrun of %llu\n",
+					vcpu->last_guest_tsc - tsc_timestamp);
 				kvm_x86_ops->adjust_tsc_offset(v,
 					vcpu->last_guest_tsc - tsc_timestamp);
+			}
 		}
 		kvm_x86_ops->set_tsc_trap(v, 0);
+		pr_debug("kvm: passing TSC vcpu%d tsc_mode: %d time_page %p\n",
+			 v->vcpu_id, vcpu->tsc_mode, vcpu->time_page);
 	}
 
 	if (catchup) {
@@ -1105,6 +1130,7 @@ static int kvm_guest_time_update(struct kvm_vcpu *v)
 				bump_guest_tsc(v, vcpu->last_guest_tsc - tsc,
 					       kernel_ns);
 			kvm_x86_ops->set_tsc_trap(v, 1);
+			pr_debug("kvm: trapping TSC on vcpu%d\n", v->vcpu_id);
 		}
 
 		/* If we're falling behind and not trapping, re-trigger */
@@ -1214,6 +1240,9 @@ static void kvm_update_tsc_trapping(struct kvm *kvm)
 	kvm_for_each_vcpu(i, vcpu, kvm) {
 		vcpu->arch.tsc_mode = best_tsc_mode(vcpu);
 		kvm_make_request(KVM_REQ_CLOCK_UPDATE, vcpu);
+		pr_debug("kvm: vcpu%d tsc_mode: %d time_page %p\n",
+			 vcpu->vcpu_id, vcpu->arch.tsc_mode,
+			 vcpu->arch.time_page);
 	}
 }
 
-- 
1.7.1

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/