Added tracing for core start-up.
authorGerd Zellweger <mail@gerdzellweger.com>
Fri, 11 Oct 2013 14:43:45 +0000 (16:43 +0200)
committerGerd Zellweger <mail@gerdzellweger.com>
Thu, 24 Oct 2013 08:26:24 +0000 (10:26 +0200)
kernel/arch/x86_64/start_aps.c
trace_definitions/trace_defs.pleco
usr/acpi/acpi.c
usr/acpi/interrupts.c
usr/kaluga/start_cpu.c
usr/monitor/arch/x86/boot.c
usr/monitor/arch/x86/inter.c
usr/monitor/boot.c

index d8a0170..9fbfcc0 100644 (file)
@@ -57,7 +57,7 @@ extern uint64_t x86_64_init_ap_global;
 int start_aps_x86_64_start(uint8_t core_id, genvaddr_t entry)
 {
     trace_event(TRACE_SUBSYS_KERNEL,
-                TRACE_EVENT_KERNEL_CORE_START_REQUEST, core_id);
+                TRACE_EVENT_KERNEL_START_CORE_REQUEST, core_id);
 
     /* Copy the startup code to the real-mode address */
     uint8_t *real_dest = (uint8_t *) local_phys_to_mem(X86_64_REAL_MODE_LINEAR_OFFSET);
@@ -128,7 +128,7 @@ int start_aps_x86_64_start(uint8_t core_id, genvaddr_t entry)
                        X86_64_REAL_MODE_SEGMENT_TO_REAL_MODE_PAGE(X86_64_REAL_MODE_SEGMENT));
 
     trace_event(TRACE_SUBSYS_KERNEL,
-                TRACE_EVENT_KERNEL_CORE_START_REQUEST_DONE, core_id);
+                TRACE_EVENT_KERNEL_CORE_START_IPI_SENT, core_id);
 
     //give the new core a bit time to start-up and set the lock
     for (uint64_t i = 0; i < STARTUP_TIMEOUT; i++) {
@@ -142,7 +142,7 @@ int start_aps_x86_64_start(uint8_t core_id, genvaddr_t entry)
     if (*ap_lock != 0) {
         while (*ap_wait != AP_STARTED);
         trace_event(TRACE_SUBSYS_KERNEL,
-                    TRACE_EVENT_KERNEL_CORE_START_REQUEST_ACK, core_id);
+                    TRACE_EVENT_KERNEL_CORE_IS_UP, core_id);
         *ap_lock = 0;
         debug(SUBSYS_STARTUP, "booted CPU%hhu\n", core_id);
         return 0;
index c047cda..42dbeee 100644 (file)
@@ -49,9 +49,10 @@ subsystem kernel {
        event SCHED_SCHEDULE            "",
        event SCHED_CURRENT             "",
 
-    event CORE_START_REQUEST      "Requested start of a new core.",
-    event CORE_START_REQUEST_DONE "Request is sent, waiting for core to come up.",
-    event CORE_START_REQUEST_ACK  "Core is online.",
+    event START_CORE_REQUEST "Received (monitor -> kernel) [in kernel].",
+    event CORE_START_IPI_SENT      "Request sent, waiting for core to appear.",
+    event CORE_IS_UP        "New kernel is online.",
+
 };
 
 subsystem threads {
@@ -102,21 +103,25 @@ subsystem memtest {
 
 
 subsystem monitor {
- event SPAN0                                   "",
- event SPAN1                                   "",
- event SPAN                                            "",
- event PCREQ                                   "",
- event PCREP                                   "",
- event PCREQ_INTER                             "",
- event PCREPLY_INTER                   "",
- event URPC_BLOCK                              "",
- event URPC_UNBLOCK                            "",
- event REMOTE_CAP_RETYPE               "",
- event REMOTE_CAP_RETYPE_RETRY "",
- event REMOTE_CAP_RETYPE_MSG   "",
- event REMOTE_CAP_RETYPE_END   "",
- event POLLING                                 "",
-
+    event SPAN0                                        "",
+    event SPAN1                                        "",
+    event SPAN                                         "",
+    event PCREQ                                        "",
+    event PCREP                                        "",
+    event PCREQ_INTER                          "",
+    event PCREPLY_INTER                        "",
+    event URPC_BLOCK                           "",
+    event URPC_UNBLOCK                         "",
+    event REMOTE_CAP_RETYPE            "",
+    event REMOTE_CAP_RETYPE_RETRY      "",
+    event REMOTE_CAP_RETYPE_MSG        "",
+    event REMOTE_CAP_RETYPE_END        "",
+    event POLLING                                      "",
+    event BIND_MONITOR_REPLY "Bind monitor reply",
+    event BIND_MONITOR_REQUEST "Request to setup connection with new monitor",
+    event BOOT_CORE_REQUEST "Received request from (user -> monitor) [in monitor].",
+    event BOOT_INITIALIZE_REQUEST "Monitor got boot initialize request",
+    event INVOKE_SPAWN "Monitor requests boot-up from kernel (monitor -> kernel).",
 };
 
 subsystem chips {
@@ -312,3 +317,13 @@ subsystem xmpl {
 
 };
 
+subsystem acpi {
+    event APIC_ADDED     "ACPI added fact about new core to SKB",
+};
+
+// Use to trace the core booting system
+subsystem cores {
+    event USER_REQUEST     "Kaluga requests boot-up of new CPU user -> monitor.",
+    event ALL_UP           "Everything has booted",
+    event BOOT_INITIALIZE_USER "User sends boot initialize to monitor",
+};
index eb0efef..615e41d 100644 (file)
@@ -25,6 +25,7 @@
 #include "acpi_shared.h"
 #include "acpi_debug.h"
 #include "ioapic.h"
+#include <trace/trace.h>
 
 struct pci_resources {
     uint8_t minbus, maxbus;
@@ -168,7 +169,7 @@ static ACPI_STATUS resource_printer(ACPI_RESOURCE *res, void *context)
     case ACPI_RESOURCE_TYPE_ADDRESS64:
         printf("length = %"PRIu32", gran = %lx, min = %lx, max = %lx, transoff "
                "= %lx, addrlen = %lx, index = %hhu, strlen = %hu, string = %s",
-               res->Length, res->Data.Address64.Granularity, 
+               res->Length, res->Data.Address64.Granularity,
                res->Data.Address64.Minimum,
                res->Data.Address64.Maximum,
                res->Data.Address64.TranslationOffset,
index 0d26714..cb0e7e1 100644 (file)
@@ -19,6 +19,7 @@
 
 #include <skb/skb.h>
 #include <octopus/getset.h>
+#include <trace/trace.h>
 
 #include "ioapic.h"
 #include "acpi_debug.h"
@@ -83,7 +84,7 @@ static errval_t init_one_ioapic(ACPI_MADT_IO_APIC *s)
     assert(ioapic_nr < IOAPIC_MAX);
 
     // allocate memory backing IOAPIC
-    err = mm_realloc_range(&pci_mm_physaddr, IOAPIC_PAGE_BITS, 
+    err = mm_realloc_range(&pci_mm_physaddr, IOAPIC_PAGE_BITS,
                            s->Address, &devmem);
     if (err_is_fail(err)) {
         DEBUG_ERR(err, "Failed to allocate I/O APIC register page at 0x%x\n",
@@ -186,6 +187,7 @@ int init_all_apics(void)
                 ACPI_DEBUG("Found local APIC: CPU = %d, ID = %d, usable = %d\n",
                        s->ProcessorId, s->Id,
                        s->LapicFlags & ACPI_MADT_ENABLED);
+                trace_event(TRACE_SUBSYS_ACPI, TRACE_EVENT_ACPI_APIC_ADDED, s->ProcessorId);
 
                 errval_t err = oct_set("hw.apic.%d { cpu_id: %d, id: %d, enabled: %d }",
                                          s->Id, s->ProcessorId, s->Id,
index 95db7bf..6dd7dcc 100644 (file)
@@ -53,6 +53,7 @@ static void send_boot_initialize_request(struct monitor_binding* b,
 {
     errval_t err;
 
+    trace_event(TRACE_SUBSYS_CORES, TRACE_EVENT_CORES_BOOT_INITIALIZE_USER, 0);
     err = b->tx_vtbl.boot_initialize_request(b,
             MKCONT(free, mm));
 
@@ -76,6 +77,7 @@ static void boot_core_reply(struct monitor_binding *st, errval_t msgerr)
             core_boot_replies+1, cores_on_boot);
 
     if (++core_boot_replies == cores_on_boot) {
+        trace_event(TRACE_SUBSYS_CORES, TRACE_EVENT_CORES_ALL_UP, 0);
         struct monitor_binding *mb = get_monitor_binding();
         struct mon_msg_state *mms = NULL;
         errval_t err = new_mon_msg(&mms, send_boot_initialize_request);
@@ -103,6 +105,7 @@ static void send_boot_core_request(struct monitor_binding* b,
     errval_t err;
 
     struct module_info* mi = find_module("cpu");
+    trace_event(TRACE_SUBSYS_CORES, TRACE_EVENT_CORES_USER_REQUEST, mm->core_id);
     err = b->tx_vtbl.boot_core_request(b, MKCONT(free, mm), mm->core_id,
             mm->arch_id, CURRENT_CPU_TYPE, mi->complete_line);
 
index 61eca9a..6ff874a 100644 (file)
@@ -375,6 +375,7 @@ errval_t spawn_xcore_monitor(coreid_t coreid, int hwid, enum cpu_type cpu_type,
     }
 
     /* Invoke kernel capability to boot new core */
+    trace_event(TRACE_SUBSYS_MONITOR, TRACE_EVENT_MONITOR_INVOKE_SPAWN, hwid);
     err = invoke_monitor_spawn_core(hwid, cpu_type, foreign_cpu_reloc_entry);
     if (err_is_fail(err)) {
         return err_push(err, MON_ERR_SPAWN_CORE);
index bd1965b..a4a5353 100644 (file)
@@ -60,10 +60,11 @@ static void send_bind_monitor_reply(struct intermon_binding *b, errval_t err)
  * with another newly booted monitor from a third monitor
  */
 static void bind_monitor_request(struct intermon_binding *b,
-                                 coreid_t core_id, 
+                                 coreid_t core_id,
                                  intermon_caprep_t caprep)
 {
     errval_t err;
+    trace_event(TRACE_SUBSYS_MONITOR, TRACE_EVENT_MONITOR_BIND_MONITOR_REQUEST, core_id);
 
     /* Create the cap */
     struct capability cap_raw;
@@ -132,6 +133,7 @@ static void bind_monitor_reply(struct intermon_binding *closure,
     if (err_is_fail(err)) {
         DEBUG_ERR(err, "Got error in bind monitor reply");
     }
+    trace_event(TRACE_SUBSYS_MONITOR, TRACE_EVENT_MONITOR_BIND_MONITOR_REPLY, 0);
     seen_connections++;
 }
 
index f45d6fe..76e86a6 100644 (file)
@@ -53,6 +53,8 @@ void boot_core_request(struct monitor_binding *b, coreid_t id, int32_t hwid,
     enum cpu_type cpu_type = (enum cpu_type)int_cpu_type;
     struct intermon_binding *new_binding = NULL;
 
+    trace_event(TRACE_SUBSYS_MONITOR, TRACE_EVENT_MONITOR_BOOT_CORE_REQUEST, id);
+
     if (id == my_core_id) {
         err = MON_ERR_SAME_CORE;
         goto out;
@@ -107,6 +109,7 @@ void boot_core_request(struct monitor_binding *b, coreid_t id, int32_t hwid,
 void boot_initialize_request(struct monitor_binding *st)
 {
     errval_t err;
+    trace_event(TRACE_SUBSYS_MONITOR, TRACE_EVENT_MONITOR_BOOT_INITIALIZE_REQUEST, 0);
 
     /* Wait for all monitors to initialize. */
     int num_connections = get_num_connections(num_monitors);