From: David Woodhouse <dwmw@amazon.co.uk>
Date: Tue, 14 Dec 2021 13:25:35 +0000 (+0000)
Subject: do_boot_cpu timing debug
X-Git-Url: https://www.infradead.org/git/?a=commitdiff_plain;h=706de61568474fc5497de291b4a1ea2c4bc37634;p=users%2Fdwmw2%2Flinux.git

do_boot_cpu timing debug
---

diff --git a/arch/x86/kernel/cpu/common.c b/arch/x86/kernel/cpu/common.c
index 98b4697b2c9b0..a533af9d200ec 100644
--- a/arch/x86/kernel/cpu/common.c
+++ b/arch/x86/kernel/cpu/common.c
@@ -1883,6 +1883,7 @@ static void wait_for_master_cpu(int cpu)
 	 * with AP initialization
 	 */
 	WARN_ON(cpumask_test_and_set_cpu(cpu, cpu_initialized_mask));
+	printk("CPU %d init at %lld\n", cpu, get_cycles());
 	while (!cpumask_test_cpu(cpu, cpu_callout_mask))
 		cpu_relax();
 #endif
diff --git a/arch/x86/kernel/smpboot.c b/arch/x86/kernel/smpboot.c
index 725fede281ace..963d72005818c 100644
--- a/arch/x86/kernel/smpboot.c
+++ b/arch/x86/kernel/smpboot.c
@@ -870,8 +870,10 @@ wakeup_secondary_cpu_via_nmi(int apicid, unsigned long start_eip)
 	return (send_status | accept_status);
 }
 
+static cycles_t t[100];
+
 static int
-wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
+wakeup_secondary_cpu_via_init(int cpu, int phys_apicid, unsigned long start_eip)
 {
 	unsigned long send_status = 0, accept_status = 0;
 	int maxlvt, num_starts, j;
@@ -888,7 +890,7 @@ wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
 	}
 
 	pr_debug("Asserting INIT\n");
-
+	t[9] = get_cycles();
 	/*
 	 * Turn INIT on target chip
 	 */
@@ -900,7 +902,7 @@ wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
 
 	pr_debug("Waiting for send to finish...\n");
 	send_status = safe_apic_wait_icr_idle();
-
+	t[10] = get_cycles();
 	udelay(init_udelay);
 
 	pr_debug("Deasserting INIT\n");
@@ -911,7 +913,7 @@ wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
 
 	pr_debug("Waiting for send to finish...\n");
 	send_status = safe_apic_wait_icr_idle();
-
+	t[11] = get_cycles();
 	mb();
 
 	/*
@@ -932,6 +934,7 @@ wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
 
 	for (j = 1; j <= num_starts; j++) {
 		pr_debug("Sending STARTUP #%d\n", j);
+		t[12 + j] = t[11 + j] = get_cycles();
 		if (maxlvt > 3)		/* Due to the Pentium erratum 3AP.  */
 			apic_write(APIC_ESR, 0);
 		apic_read(APIC_ESR);
@@ -973,9 +976,13 @@ wakeup_secondary_cpu_via_init(int phys_apicid, unsigned long start_eip)
 		accept_status = (apic_read(APIC_ESR) & 0xEF);
 		if (send_status || accept_status)
 			break;
+		if (cpumask_test_cpu(cpu, cpu_initialized_mask)) {
+			printk("CPU %d already up after SIPI %d", cpu, j);
+			break;
+		}
 	}
 	pr_debug("After Startup\n");
-
+	t[14] = get_cycles();
 	if (send_status)
 		pr_err("APIC never delivered???\n");
 	if (accept_status)
@@ -1057,7 +1064,7 @@ wakeup_cpu_via_init_nmi(int cpu, unsigned long start_ip, int apicid,
 	 * Wake up AP by INIT, INIT, STARTUP sequence.
 	 */
 	if (cpu) {
-		boot_error = wakeup_secondary_cpu_via_init(apicid, start_ip);
+		boot_error = wakeup_secondary_cpu_via_init(cpu, apicid, start_ip);
 		goto out;
 	}
 
@@ -1133,13 +1140,14 @@ static int do_boot_cpu(int apicid, int cpu, struct task_struct *idle,
 	} else {
 		smpboot_control = STARTUP_USE_CPUID_0B;
 	}
-
+	t[5] = get_cycles();
 	/* Enable the espfix hack for this CPU */
 	init_espfix_ap(cpu);
-
+	t[6] = get_cycles();
 	/* So we see what's up */
 	announce_cpu(cpu, apicid);
-
+	t[7] = get_cycles();
+	
 	/*
 	 * This grunge runs the startup process for
 	 * the targeted processor.
@@ -1158,7 +1166,7 @@ static int do_boot_cpu(int apicid, int cpu, struct task_struct *idle,
 			apic_read(APIC_ESR);
 		}
 	}
-
+	t[8] = get_cycles();
 	/*
 	 * AP might wait on cpu_callout_mask in cpu_init() with
 	 * cpu_initialized_mask set if previous attempt to online
@@ -1179,7 +1187,13 @@ static int do_boot_cpu(int apicid, int cpu, struct task_struct *idle,
 	else
 		boot_error = wakeup_cpu_via_init_nmi(cpu, start_ip, apicid,
 						     cpu0_nmi_registered);
+	t[15] = get_cycles();
 
+	printk("Bringup CPU%d: %lld %lld %lld %lld .  %lld %lld %lld %lld . %lld %lld %lld %lld . %lld %lld %lld (t14 %lld)\n",
+	       cpu, t[1] - t[0],
+	       t[2] - t[1], t[3] - t[2], t[4] - t[3], t[5] - t[4], t[6] - t[5], t[7] -t[6], t[8] - t[7],
+	       t[9] - t[8], t[10] - t[9], t[11] - t[10], t[12] - t[11], t[13] - t[12], t[14] - t[13],
+	       t[15] - t[14], t[14]);
 	return boot_error;
 }
 
@@ -1274,6 +1288,8 @@ int do_cpu_up(unsigned int cpu, struct task_struct *tidle)
 
 	pr_debug("++++++++++++++++++++=_---CPU UP  %u\n", cpu);
 
+	t[0] = get_cycles();
+
 	if (apicid == BAD_APICID ||
 	    !physid_isset(apicid, phys_cpu_present_map) ||
 	    !apic->apic_id_valid(apicid)) {
@@ -1293,12 +1309,15 @@ int do_cpu_up(unsigned int cpu, struct task_struct *tidle)
 	 * Save current MTRR state in case it was changed since early boot
 	 * (e.g. by the ACPI SMI) to initialize new CPUs with MTRRs in sync:
 	 */
+	t[1] = get_cycles();
 	mtrr_save_state();
+	t[2] = get_cycles();
 
 	/* x86 CPUs take themselves offline, so delayed offline is OK. */
 	err = cpu_check_up_prepare(cpu);
 	if (err && err != -EBUSY)
 		return err;
+	t[3] = get_cycles();
 
 	/* the FPU context is blank, nobody can own it */
 	per_cpu(fpu_fpregs_owner_ctx, cpu) = NULL;
@@ -1306,6 +1325,7 @@ int do_cpu_up(unsigned int cpu, struct task_struct *tidle)
 	err = common_cpu_up(cpu, tidle);
 	if (err)
 		return err;
+	t[4] = get_cycles();
 
 	err = do_boot_cpu(apicid, cpu, tidle, &cpu0_nmi_registered);
 	if (err) {