Support different log levels.
This will let us add more verbose logs for debugging but have them
compiled out most of the time.
Change-Id: Iaae468e41025a165b5e67fa6fec5422f004c6a44
diff --git a/build/BUILD.gn b/build/BUILD.gn
index 8ce649c..ed5119d 100644
--- a/build/BUILD.gn
+++ b/build/BUILD.gn
@@ -48,11 +48,6 @@
"HEAP_PAGES=${plat_heap_pages}",
"MAX_CPUS=${plat_max_cpus}",
"MAX_VMS=${plat_max_vms}",
+ "LOG_LEVEL=${log_level}",
]
-
- if (is_debug) {
- defines += [ "DEBUG=1" ]
- } else {
- defines += [ "DEBUG=0" ]
- }
}
diff --git a/build/BUILDCONFIG.gn b/build/BUILDCONFIG.gn
index 134ddcd..d888563 100644
--- a/build/BUILDCONFIG.gn
+++ b/build/BUILDCONFIG.gn
@@ -17,13 +17,14 @@
# The name of the project being built.
project = "reference"
- # Enable extra debugging.
- is_debug = true
-
# Whether to build against the platform for embedded images consisting of
# include paths and defines. This is also used for host targets that simulate
# an embedded image.
use_platform = false
+
+ # The level of debug logs to include. This should match one of the levels
+ # defined in dlog.h.
+ log_level = "LOG_LEVEL_INFO"
}
# Check that we support the attempted build.
diff --git a/docs/StyleGuide.md b/docs/StyleGuide.md
index 3cdd290..f158350 100644
--- a/docs/StyleGuide.md
+++ b/docs/StyleGuide.md
@@ -81,3 +81,45 @@
* No self-modifying code.
* Build targets should include all the direct dependencies for their sources,
where possible, rather than relying on transitive dependencies.
+
+## Logging
+
+Hafnium uses the same log levels as Arm Trusted Firmware. There are 5 log
+levels, in order of severity:
+
+1. `ERROR`
+
+ Use this only for cases that there is an error in the hypervisor itself,
+ perhaps caused by a coding error, bad configuration, unexpected hardware
+ behaviour or a malformed manifest. Errors should not be logged during normal
+ operation, even in case of a buggy or malicious VM.
+
+2. `NOTICE`
+
+ Use this sparingly for important messages which should be logged even in
+ production builds because they will be useful for debugging. This is a
+ suitable level to use for events which may indicate a bug in a VM.
+
+3. `WARNING`
+
+ Use this for warnings which are important to developers but can generally be
+ ignored in production.
+
+4. `INFO`
+
+ Use this to provide extra information that is helpful for developers.
+
+5. `VERBOSE`
+
+ Use this to provide even more information which may be helpful when tracing
+ through execution in detail, such as when debugging test failures. This is
+ the only level which should include any sensitive data.
+
+Logging is done with the `dlog_*` macros, e.g. `dlog_info`. These accept
+printf-style format strings and arguments.
+
+The log level of a build is controlled by the `log_level` argument defined in
+[`BUILDCONFIG.gn`](../build/BUILDCONFIG.gn). This defaults to `INFO` for debug
+builds and tests, meaning that all levels except `VERBOSE` will be logged. It is
+recommended to set the log level to `NOTICE` for production builds, to reduce
+binary size and log spam.
diff --git a/inc/hf/dlog.h b/inc/hf/dlog.h
index f8c0080..5451f85 100644
--- a/inc/hf/dlog.h
+++ b/inc/hf/dlog.h
@@ -23,17 +23,48 @@
#define DLOG_BUFFER_SIZE 8192
+#define LOG_LEVEL_NONE UINT32_C(0)
+#define LOG_LEVEL_ERROR UINT32_C(1)
+#define LOG_LEVEL_NOTICE UINT32_C(2)
+#define LOG_LEVEL_WARNING UINT32_C(3)
+#define LOG_LEVEL_INFO UINT32_C(4)
+#define LOG_LEVEL_VERBOSE UINT32_C(5)
+
extern size_t dlog_buffer_offset;
extern char dlog_buffer[];
-#if DEBUG
void dlog_enable_lock(void);
void dlog(const char *fmt, ...);
void vdlog(const char *fmt, va_list args);
+
+#if LOG_LEVEL >= LOG_LEVEL_ERROR
+#define dlog_error(...) dlog("ERROR: " __VA_ARGS__)
#else
-#define dlog_enable_lock()
-#define dlog(...)
-#define vdlog(fmt, args)
+#define dlog_error(...)
+#endif
+
+#if LOG_LEVEL >= LOG_LEVEL_NOTICE
+#define dlog_notice(...) dlog("NOTICE: " __VA_ARGS__)
+#else
+#define dlog_notice(...)
+#endif
+
+#if LOG_LEVEL >= LOG_LEVEL_WARNING
+#define dlog_warning(...) dlog("WARNING: " __VA_ARGS__)
+#else
+#define dlog_warning(...)
+#endif
+
+#if LOG_LEVEL >= LOG_LEVEL_INFO
+#define dlog_info(...) dlog("INFO: " __VA_ARGS__)
+#else
+#define dlog_info(...)
+#endif
+
+#if LOG_LEVEL >= LOG_LEVEL_VERBOSE
+#define dlog_verbose(...) dlog("VERBOSE: " __VA_ARGS__)
+#else
+#define dlog_verbose(...)
#endif
void dlog_flush_vm_buffer(spci_vm_id_t id, char buffer[], size_t length);
diff --git a/src/BUILD.gn b/src/BUILD.gn
index 70eafd1..49fb3ac 100644
--- a/src/BUILD.gn
+++ b/src/BUILD.gn
@@ -64,6 +64,7 @@
deps = [
":abort",
+ ":dlog",
":fdt",
":fdt_handler",
":memiter",
@@ -74,10 +75,6 @@
plat_console,
plat_iommu,
]
-
- if (is_debug) {
- deps += [ ":dlog" ]
- }
}
source_set("layout") {
@@ -132,12 +129,9 @@
"fdt_handler.c",
]
deps = [
+ ":dlog",
":fdt",
]
-
- if (is_debug) {
- deps += [ ":dlog" ]
- }
}
# Flattened Device Tree (FDT) utilities.
@@ -147,12 +141,9 @@
]
deps = [
+ ":dlog",
":std",
]
-
- if (is_debug) {
- deps += [ ":dlog" ]
- }
}
source_set("memiter") {
diff --git a/src/api.c b/src/api.c
index 825cb42..aa6c7c1 100644
--- a/src/api.c
+++ b/src/api.c
@@ -207,7 +207,8 @@
{
struct spci_value ret = spci_error(SPCI_ABORTED);
- dlog("Aborting VM %u vCPU %u\n", current->vm->id, vcpu_index(current));
+ dlog_notice("Aborting VM %u vCPU %u\n", current->vm->id,
+ vcpu_index(current));
if (current->vm->id == HF_PRIMARY_VM_ID) {
/* TODO: what to do when the primary aborts? */
@@ -384,8 +385,8 @@
.arg4 = receiver->mailbox.recv_size};
default:
/* This should never be reached, but return an error in case. */
- dlog("Tried to return an invalid message function %#x\n",
- receiver->mailbox.recv_func);
+ dlog_error("Tried to return an invalid message function %#x\n",
+ receiver->mailbox.recv_func);
return spci_error(SPCI_DENIED);
}
}
@@ -444,8 +445,8 @@
if (atomic_load_explicit(&vcpu->vm->aborting, memory_order_relaxed)) {
if (vcpu->state != VCPU_STATE_ABORTED) {
- dlog("Aborting VM %u vCPU %u\n", vcpu->vm->id,
- vcpu_index(vcpu));
+ dlog_notice("Aborting VM %u vCPU %u\n", vcpu->vm->id,
+ vcpu_index(vcpu));
vcpu->state = VCPU_STATE_ABORTED;
}
ret = false;
@@ -1365,8 +1366,9 @@
target_vcpu = vm_get_vcpu(target_vm, target_vcpu_idx);
- dlog("Injecting IRQ %d for VM %d vCPU %d from VM %d vCPU %d\n", intid,
- target_vm_id, target_vcpu_idx, current->vm->id, current->cpu->id);
+ dlog_info("Injecting IRQ %d for VM %d vCPU %d from VM %d vCPU %d\n",
+ intid, target_vm_id, target_vcpu_idx, current->vm->id,
+ current->cpu->id);
return internal_interrupt_inject(target_vcpu, intid, current, next);
}
diff --git a/src/arch/aarch64/hftest/interrupts_gicv3.c b/src/arch/aarch64/hftest/interrupts_gicv3.c
index 9010ce1..ed6a745 100644
--- a/src/arch/aarch64/hftest/interrupts_gicv3.c
+++ b/src/arch/aarch64/hftest/interrupts_gicv3.c
@@ -35,18 +35,19 @@
/* Mark CPU as awake. */
io_write32(GICR_WAKER, io_read32(GICR_WAKER) & ~(1U << 1));
while ((io_read32(GICR_WAKER) & (1U << 2)) != 0) {
- dlog("Waiting for ChildrenAsleep==0\n");
+ dlog_info("Waiting for ChildrenAsleep==0\n");
}
/* Put interrupts into non-secure group 1. */
- dlog("GICR_IGROUPR0 was %x\n", 0xffffffff, io_read32(GICR_IGROUPR0));
+ dlog_info("GICR_IGROUPR0 was %x\n", 0xffffffff,
+ io_read32(GICR_IGROUPR0));
io_write32(GICR_IGROUPR0, 0xffffffff);
- dlog("wrote %x to GICR_IGROUPR0, got back %x\n", 0xffffffff,
- io_read32(GICR_IGROUPR0));
+ dlog_info("wrote %x to GICR_IGROUPR0, got back %x\n", 0xffffffff,
+ io_read32(GICR_IGROUPR0));
/* Enable non-secure group 1. */
write_msr(ICC_IGRPEN1_EL1, 0x00000001);
- dlog("wrote %x to ICC_IGRPEN1_EL1, got back %x\n", 0x00000001,
- read_msr(ICC_IGRPEN1_EL1));
+ dlog_info("wrote %x to ICC_IGRPEN1_EL1, got back %x\n", 0x00000001,
+ read_msr(ICC_IGRPEN1_EL1));
}
void interrupt_enable(uint32_t intid, bool enable)
diff --git a/src/arch/aarch64/hftest/mm.c b/src/arch/aarch64/hftest/mm.c
index 60ca2f0..6a17c2f 100644
--- a/src/arch/aarch64/hftest/mm.c
+++ b/src/arch/aarch64/hftest/mm.c
@@ -46,14 +46,15 @@
/* Check that 4KB granules are supported. */
if ((features >> 28) & 0xf) {
- dlog("4KB granules are not supported\n");
+ dlog_error("4KB granules are not supported\n");
return false;
}
/* Check the physical address range. */
if (!pa_bits) {
- dlog("Unsupported value of id_aa64mmfr0_el1.PARange: %x\n",
- features & 0xf);
+ dlog_error(
+ "Unsupported value of id_aa64mmfr0_el1.PARange: %x\n",
+ features & 0xf);
return false;
}
diff --git a/src/arch/aarch64/hypervisor/debug_el1.c b/src/arch/aarch64/hypervisor/debug_el1.c
index 45e69b0..f46cbe6 100644
--- a/src/arch/aarch64/hypervisor/debug_el1.c
+++ b/src/arch/aarch64/hypervisor/debug_el1.c
@@ -170,11 +170,13 @@
#undef X
default:
value = vcpu->regs.r[rt_register];
- dlog("Unsupported debug system register read: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr),
- GET_ISS_CRN(esr), GET_ISS_CRM(esr),
- GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported debug system register read: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, "
+ "rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr),
+ GET_ISS_CRN(esr), GET_ISS_CRM(esr),
+ GET_ISS_OP2(esr), GET_ISS_RT(esr));
break;
}
if (rt_register != RT_REG_XZR) {
@@ -195,11 +197,13 @@
EL1_DEBUG_REGISTERS_READ_WRITE
#undef X
default:
- dlog("Unsupported debug system register write: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr),
- GET_ISS_CRN(esr), GET_ISS_CRM(esr),
- GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported debug system register write: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, "
+ "rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr),
+ GET_ISS_CRN(esr), GET_ISS_CRM(esr),
+ GET_ISS_OP2(esr), GET_ISS_RT(esr));
break;
}
}
diff --git a/src/arch/aarch64/hypervisor/feature_id.c b/src/arch/aarch64/hypervisor/feature_id.c
index c305b1c..eed0d5e 100644
--- a/src/arch/aarch64/hypervisor/feature_id.c
+++ b/src/arch/aarch64/hypervisor/feature_id.c
@@ -253,10 +253,11 @@
CHECK(rt_register < NUM_GP_REGS + 1);
if (!ISS_IS_READ(esr)) {
- dlog("Unsupported feature ID register write: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr), GET_ISS_CRN(esr),
- GET_ISS_CRM(esr), GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported feature ID register write: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr), GET_ISS_CRN(esr),
+ GET_ISS_CRM(esr), GET_ISS_OP2(esr), GET_ISS_RT(esr));
return true;
}
@@ -270,10 +271,11 @@
default:
/* Reserved registers should be read as zero (raz). */
value = 0;
- dlog("Unsupported feature ID register read: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr), GET_ISS_CRN(esr),
- GET_ISS_CRM(esr), GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported feature ID register read: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr), GET_ISS_CRN(esr),
+ GET_ISS_CRM(esr), GET_ISS_OP2(esr), GET_ISS_RT(esr));
break;
}
diff --git a/src/arch/aarch64/hypervisor/handler.c b/src/arch/aarch64/hypervisor/handler.c
index fe32c5a..b4646d3 100644
--- a/src/arch/aarch64/hypervisor/handler.c
+++ b/src/arch/aarch64/hypervisor/handler.c
@@ -203,20 +203,25 @@
switch (ec) {
case EC_DATA_ABORT_SAME_EL:
- dlog("Data abort: pc=%#x, esr=%#x, ec=%#x", elr, esr, ec);
if (!(esr & (1U << 10))) { /* Check FnV bit. */
- dlog(", far=%#x", read_msr(far_el2));
+ dlog_error(
+ "Data abort: pc=%#x, esr=%#x, ec=%#x, "
+ "far=%#x\n",
+ elr, esr, ec, read_msr(far_el2));
} else {
- dlog(", far=invalid");
+ dlog_error(
+ "Data abort: pc=%#x, esr=%#x, ec=%#x, "
+ "far=invalid\n",
+ elr, esr, ec);
}
- dlog("\n");
break;
default:
- dlog("Unknown current sync exception pc=%#x, esr=%#x, "
- "ec=%#x\n",
- elr, esr, ec);
+ dlog_error(
+ "Unknown current sync exception pc=%#x, esr=%#x, "
+ "ec=%#x\n",
+ elr, esr, ec);
break;
}
@@ -264,8 +269,8 @@
}
}
- dlog("SMC %#010x attempted from VM %d, blocked=%d\n", func, vm->id,
- block_by_default);
+ dlog_notice("SMC %#010x attempted from VM %d, blocked=%d\n", func,
+ vm->id, block_by_default);
/* Access is still allowed in permissive mode. */
return block_by_default;
@@ -526,7 +531,8 @@
uintreg_t esr_el1_value = GET_ESR_ISS(esr_el2) | GET_ESR_IL(esr_el2) |
(EC_DATA_ABORT_SAME_EL << ESR_EC_OFFSET);
- dlog("Injecting Data Abort exception into VM%d.\n", vcpu->vm->id);
+ dlog_notice("Injecting Data Abort exception into VM%d.\n",
+ vcpu->vm->id);
inject_el1_exception(vcpu, esr_el1_value);
}
@@ -546,8 +552,8 @@
GET_ESR_ISS(esr_el2) | GET_ESR_IL(esr_el2) |
(EC_INSTRUCTION_ABORT_SAME_EL << ESR_EC_OFFSET);
- dlog("Injecting Instruction Abort exception into VM%d.\n",
- vcpu->vm->id);
+ dlog_notice("Injecting Instruction Abort exception into VM%d.\n",
+ vcpu->vm->id);
inject_el1_exception(vcpu, esr_el1_value);
}
@@ -562,13 +568,15 @@
char *direction_str;
direction_str = ISS_IS_READ(esr_el2) ? "read" : "write";
- dlog("Trapped access to system register %s: op0=%d, op1=%d, crn=%d, "
- "crm=%d, op2=%d, rt=%d.\n",
- direction_str, GET_ISS_OP0(esr_el2), GET_ISS_OP1(esr_el2),
- GET_ISS_CRN(esr_el2), GET_ISS_CRM(esr_el2), GET_ISS_OP2(esr_el2),
- GET_ISS_RT(esr_el2));
+ dlog_notice(
+ "Trapped access to system register %s: op0=%d, op1=%d, crn=%d, "
+ "crm=%d, op2=%d, rt=%d.\n",
+ direction_str, GET_ISS_OP0(esr_el2), GET_ISS_OP1(esr_el2),
+ GET_ISS_CRN(esr_el2), GET_ISS_CRM(esr_el2),
+ GET_ISS_OP2(esr_el2), GET_ISS_RT(esr_el2));
- dlog("Injecting Unknown Reason exception into VM%d.\n", vcpu->vm->id);
+ dlog_notice("Injecting Unknown Reason exception into VM%d.\n",
+ vcpu->vm->id);
inject_el1_exception(vcpu, esr_el1_value);
}
@@ -772,9 +780,10 @@
panic("Handled by handle_system_register_access().");
default:
- dlog("Unknown lower sync exception pc=%#x, esr=%#x, "
- "ec=%#x\n",
- vcpu->regs.pc, esr, ec);
+ dlog_notice(
+ "Unknown lower sync exception pc=%#x, esr=%#x, "
+ "ec=%#x\n",
+ vcpu->regs.pc, esr, ec);
break;
}
diff --git a/src/arch/aarch64/hypervisor/perfmon.c b/src/arch/aarch64/hypervisor/perfmon.c
index 9aea3ff..4532e31 100644
--- a/src/arch/aarch64/hypervisor/perfmon.c
+++ b/src/arch/aarch64/hypervisor/perfmon.c
@@ -186,11 +186,14 @@
#undef X
default:
value = vcpu->regs.r[rt_register];
- dlog("Unsupported performance monitor register read: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr),
- GET_ISS_CRN(esr), GET_ISS_CRM(esr),
- GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported performance monitor register "
+ "read: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, "
+ "rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr),
+ GET_ISS_CRN(esr), GET_ISS_CRM(esr),
+ GET_ISS_OP2(esr), GET_ISS_RT(esr));
break;
}
if (rt_register != RT_REG_XZR) {
@@ -211,11 +214,14 @@
PERFMON_REGISTERS_READ_WRITE
#undef X
default:
- dlog("Unsupported performance monitor register write: "
- "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, rt=%d.\n",
- GET_ISS_OP0(esr), GET_ISS_OP1(esr),
- GET_ISS_CRN(esr), GET_ISS_CRM(esr),
- GET_ISS_OP2(esr), GET_ISS_RT(esr));
+ dlog_notice(
+ "Unsupported performance monitor register "
+ "write: "
+ "op0=%d, op1=%d, crn=%d, crm=%d, op2=%d, "
+ "rt=%d.\n",
+ GET_ISS_OP0(esr), GET_ISS_OP1(esr),
+ GET_ISS_CRN(esr), GET_ISS_CRM(esr),
+ GET_ISS_OP2(esr), GET_ISS_RT(esr));
break;
}
}
diff --git a/src/arch/aarch64/hypervisor/psci_handler.c b/src/arch/aarch64/hypervisor/psci_handler.c
index 1d638e4..147f9eb 100644
--- a/src/arch/aarch64/hypervisor/psci_handler.c
+++ b/src/arch/aarch64/hypervisor/psci_handler.c
@@ -48,12 +48,12 @@
case PSCI_VERSION_1_0:
case PSCI_VERSION_1_1:
/* Supported EL3 PSCI version. */
- dlog("Found PSCI version: %#x\n", el3_psci_version);
+ dlog_info("Found PSCI version: %#x\n", el3_psci_version);
break;
default:
/* Unsupported EL3 PSCI version. Log a warning but continue. */
- dlog("Warning: unknown PSCI version: %#x\n", el3_psci_version);
+ dlog_warning("Unknown PSCI version: %#x\n", el3_psci_version);
el3_psci_version = 0;
break;
}
diff --git a/src/arch/aarch64/mm.c b/src/arch/aarch64/mm.c
index 11b4877..f47ff80 100644
--- a/src/arch/aarch64/mm.c
+++ b/src/arch/aarch64/mm.c
@@ -599,18 +599,19 @@
/* Check that 4KB granules are supported. */
if ((features >> 28) & 0xf) {
- dlog("4KB granules are not supported\n");
+ dlog_error("4KB granules are not supported\n");
return false;
}
/* Check the physical address range. */
if (!pa_bits) {
- dlog("Unsupported value of id_aa64mmfr0_el1.PARange: %x\n",
- features & 0xf);
+ dlog_error(
+ "Unsupported value of id_aa64mmfr0_el1.PARange: %x\n",
+ features & 0xf);
return false;
}
- dlog("Supported bits in physical address: %d\n", pa_bits);
+ dlog_info("Supported bits in physical address: %d\n", pa_bits);
/*
* Determine sl0, starting level of the page table, based on the number
@@ -644,8 +645,9 @@
}
mm_s2_root_table_count = 1 << extend_bits;
- dlog("Stage 2 has %d page table levels with %d pages at the root.\n",
- mm_s2_max_level + 1, mm_s2_root_table_count);
+ dlog_info(
+ "Stage 2 has %d page table levels with %d pages at the root.\n",
+ mm_s2_max_level + 1, mm_s2_root_table_count);
arch_mm_config = (struct arch_mm_config){
.ttbr0_el2 = pa_addr(table),
diff --git a/src/arch/aarch64/qemuloader/loader.c b/src/arch/aarch64/qemuloader/loader.c
index 84621bf..f869e07 100644
--- a/src/arch/aarch64/qemuloader/loader.c
+++ b/src/arch/aarch64/qemuloader/loader.c
@@ -55,18 +55,18 @@
ret = fdt_check_header(fdt);
if (ret != 0) {
- dlog("FDT failed validation: %d\n", ret);
+ dlog_error("FDT failed validation: %d\n", ret);
return false;
}
ret = fdt_open_into(fdt, fdt, FDT_MAX_SIZE);
if (ret != 0) {
- dlog("FDT failed to open: %d\n", ret);
+ dlog_error("FDT failed to open: %d\n", ret);
return false;
}
chosen_offset = fdt_path_offset(fdt, "/chosen");
if (chosen_offset <= 0) {
- dlog("Unable to find '/chosen'\n");
+ dlog_error("Unable to find '/chosen'\n");
return false;
}
@@ -74,20 +74,20 @@
ret = fdt_setprop_u64(fdt, chosen_offset, "linux,initrd-start",
initrd_start);
if (ret != 0) {
- dlog("Unable to write linux,initrd-start: %d\n", ret);
+ dlog_error("Unable to write linux,initrd-start: %d\n", ret);
return false;
}
ret = fdt_setprop_u64(fdt, chosen_offset, "linux,initrd-end",
initrd_end);
if (ret != 0) {
- dlog("Unable to write linux,initrd-end\n");
+ dlog_error("Unable to write linux,initrd-end\n");
return false;
}
ret = fdt_pack(fdt);
if (ret != 0) {
- dlog("Failed to pack FDT.\n");
+ dlog_error("Failed to pack FDT.\n");
return false;
}
@@ -104,7 +104,7 @@
uintptr_t initrd_start = align_up(pa_addr(image_end), LINUX_ALIGNMENT);
uint32_t initrd_size = fw_cfg_read_uint32(FW_CFG_INITRD_SIZE);
- dlog("Initrd start %#x, size %#x\n", initrd_start, initrd_size);
+ dlog_info("Initrd start %#x, size %#x\n", initrd_start, initrd_size);
fw_cfg_read_bytes(FW_CFG_INITRD_DATA, initrd_start, initrd_size);
/*
@@ -114,13 +114,13 @@
kernel_start = align_up(initrd_start + initrd_size, LINUX_ALIGNMENT) +
LINUX_OFFSET;
kernel_size = fw_cfg_read_uint32(FW_CFG_KERNEL_SIZE);
- dlog("Kernel start %#x, size %#x\n", kernel_start, kernel_size);
+ dlog_info("Kernel start %#x, size %#x\n", kernel_start, kernel_size);
fw_cfg_read_bytes(FW_CFG_KERNEL_DATA, kernel_start, kernel_size);
/* Update FDT to point to initrd. */
if (initrd_size > 0) {
if (update_fdt(fdt, initrd_start, initrd_size)) {
- dlog("Updated FDT with initrd.\n");
+ dlog_info("Updated FDT with initrd.\n");
} else {
panic("Failed to update FDT.");
}
diff --git a/src/arch/fake/hypervisor/tee.c b/src/arch/fake/hypervisor/tee.c
index 317e279..6f1eaca 100644
--- a/src/arch/fake/hypervisor/tee.c
+++ b/src/arch/fake/hypervisor/tee.c
@@ -22,6 +22,6 @@
struct spci_value arch_tee_call(struct spci_value args)
{
- dlog("Attempted to call TEE function %#x\n", args.func);
+ dlog_error("Attempted to call TEE function %#x\n", args.func);
return spci_error(SPCI_NOT_SUPPORTED);
}
diff --git a/src/boot_flow/linux.c b/src/boot_flow/linux.c
index e1e257c..a3dff65 100644
--- a/src/boot_flow/linux.c
+++ b/src/boot_flow/linux.c
@@ -63,8 +63,8 @@
if (string_is_empty(filename)) {
memiter_init(&primary_initrd, NULL, 0);
} else if (!cpio_get_file(cpio, filename, &primary_initrd)) {
- dlog("Unable to find primary initrd \"%s\".\n",
- string_data(filename));
+ dlog_error("Unable to find primary initrd \"%s\".\n",
+ string_data(filename));
return false;
}
diff --git a/src/cpu.c b/src/cpu.c
index 02c312f..e52fe2d 100644
--- a/src/cpu.c
+++ b/src/cpu.c
@@ -116,7 +116,7 @@
if (!found_boot_cpu) {
/* Boot CPU was initialized but with wrong ID. */
- dlog("Boot CPU's ID not found in config.\n");
+ dlog_warning("Boot CPU's ID not found in config.\n");
cpus[0].id = boot_cpu_id;
}
}
diff --git a/src/fdt.c b/src/fdt.c
index b046662..85d1d0a 100644
--- a/src/fdt.c
+++ b/src/fdt.c
@@ -386,7 +386,7 @@
/* Traverse the whole thing. */
if (!fdt_root_node(&node, hdr)) {
- dlog("FDT failed validation.\n");
+ dlog_error("FDT failed validation.\n");
return;
}
diff --git a/src/fdt_handler.c b/src/fdt_handler.c
index 057a2ca..ada6a15 100644
--- a/src/fdt_handler.c
+++ b/src/fdt_handler.c
@@ -89,17 +89,17 @@
uint64_t initrd_end;
if (!fdt_find_child(&n, "chosen")) {
- dlog("Unable to find 'chosen'\n");
+ dlog_error("Unable to find 'chosen'\n");
return false;
}
if (!fdt_read_number(&n, "linux,initrd-start", &initrd_begin)) {
- dlog("Unable to read linux,initrd-start\n");
+ dlog_error("Unable to read linux,initrd-start\n");
return false;
}
if (!fdt_read_number(&n, "linux,initrd-end", &initrd_end)) {
- dlog("Unable to read linux,initrd-end\n");
+ dlog_error("Unable to read linux,initrd-end\n");
return false;
}
@@ -119,7 +119,7 @@
*cpu_count = 0;
if (!fdt_find_child(&n, "cpus")) {
- dlog("Unable to find 'cpus'\n");
+ dlog_error("Unable to find 'cpus'\n");
return false;
}
@@ -149,12 +149,13 @@
uint64_t value;
if (*cpu_count >= MAX_CPUS) {
- dlog("Found more than %d CPUs\n", MAX_CPUS);
+ dlog_error("Found more than %d CPUs\n",
+ MAX_CPUS);
return false;
}
if (!fdt_parse_number(data, address_size, &value)) {
- dlog("Could not parse CPU id\n");
+ dlog_error("Could not parse CPU id\n");
return false;
}
cpu_ids[(*cpu_count)++] = value;
@@ -223,10 +224,11 @@
pa_init(addr + len);
++mem_range_index;
} else {
- dlog("Found memory range %u in FDT but only "
- "%u supported, ignoring additional range "
- "of size %u.\n",
- mem_range_index, MAX_MEM_RANGES, len);
+ dlog_error(
+ "Found memory range %u in FDT but only "
+ "%u supported, ignoring additional "
+ "range of size %u.\n",
+ mem_range_index, MAX_MEM_RANGES, len);
}
size -= entry_size;
@@ -251,12 +253,12 @@
pa_add(fdt_addr, fdt_header_size()), MM_MODE_R,
ppool);
if (!fdt) {
- dlog("Unable to map FDT header.\n");
+ dlog_error("Unable to map FDT header.\n");
return NULL;
}
if (!fdt_root_node(n, fdt)) {
- dlog("FDT failed validation.\n");
+ dlog_error("FDT failed validation.\n");
goto fail;
}
@@ -265,7 +267,7 @@
pa_add(fdt_addr, fdt_total_size(fdt)), MM_MODE_R,
ppool);
if (!fdt) {
- dlog("Unable to map full FDT.\n");
+ dlog_error("Unable to map full FDT.\n");
goto fail;
}
@@ -299,12 +301,12 @@
pa_add(fdt_addr, fdt_header_size()), MM_MODE_R,
ppool);
if (!fdt) {
- dlog("Unable to map FDT header.\n");
+ dlog_error("Unable to map FDT header.\n");
return false;
}
if (!fdt_root_node(&n, fdt)) {
- dlog("FDT failed validation.\n");
+ dlog_error("FDT failed validation.\n");
goto err_unmap_fdt_header;
}
@@ -313,29 +315,29 @@
pa_add(fdt_addr, fdt_total_size(fdt) + PAGE_SIZE),
MM_MODE_R | MM_MODE_W, ppool);
if (!fdt) {
- dlog("Unable to map FDT in r/w mode.\n");
+ dlog_error("Unable to map FDT in r/w mode.\n");
goto err_unmap_fdt_header;
}
if (!fdt_find_child(&n, "")) {
- dlog("Unable to find FDT root node.\n");
+ dlog_error("Unable to find FDT root node.\n");
goto out_unmap_fdt;
}
if (!fdt_find_child(&n, "chosen")) {
- dlog("Unable to find 'chosen'\n");
+ dlog_error("Unable to find 'chosen'\n");
goto out_unmap_fdt;
}
/* Patch FDT to point to new ramdisk. */
if (!fdt_write_number(&n, "linux,initrd-start",
pa_addr(p->initrd_begin))) {
- dlog("Unable to write linux,initrd-start\n");
+ dlog_error("Unable to write linux,initrd-start\n");
goto out_unmap_fdt;
}
if (!fdt_write_number(&n, "linux,initrd-end", pa_addr(p->initrd_end))) {
- dlog("Unable to write linux,initrd-end\n");
+ dlog_error("Unable to write linux,initrd-end\n");
goto out_unmap_fdt;
}
@@ -368,7 +370,7 @@
if (!mm_unmap(stage1_locked, fdt_addr,
pa_add(fdt_addr, fdt_total_size(fdt) + PAGE_SIZE),
ppool)) {
- dlog("Unable to unmap writable FDT.\n");
+ dlog_error("Unable to unmap writable FDT.\n");
return false;
}
return ret;
diff --git a/src/init.c b/src/init.c
index 34cabd9..608dac0 100644
--- a/src/init.c
+++ b/src/init.c
@@ -56,7 +56,7 @@
/* Make sure the console is initialised before calling dlog. */
plat_console_init();
- dlog("Initialising hafnium\n");
+ dlog_notice("Initialising hafnium\n");
mpool_init(&ppool, sizeof(struct mm_page_table));
mpool_add_chunk(&ppool, ptable_buf, sizeof(ptable_buf));
@@ -107,13 +107,13 @@
}
for (i = 0; i < params.mem_ranges_count; ++i) {
- dlog("Memory range: %#x - %#x\n",
- pa_addr(params.mem_ranges[i].begin),
- pa_addr(params.mem_ranges[i].end) - 1);
+ dlog_info("Memory range: %#x - %#x\n",
+ pa_addr(params.mem_ranges[i].begin),
+ pa_addr(params.mem_ranges[i].end) - 1);
}
- dlog("Ramdisk range: %#x - %#x\n", pa_addr(params.initrd_begin),
- pa_addr(params.initrd_end) - 1);
+ dlog_info("Ramdisk range: %#x - %#x\n", pa_addr(params.initrd_begin),
+ pa_addr(params.initrd_end) - 1);
/* Map initrd in, and initialise cpio parser. */
initrd = mm_identity_map(mm_stage1_locked, params.initrd_begin,
@@ -166,5 +166,5 @@
/* Enable TLB invalidation for VM page table updates. */
mm_vm_enable_invalidation();
- dlog("Hafnium initialisation completed\n");
+ dlog_info("Hafnium initialisation completed\n");
}
diff --git a/src/load.c b/src/load.c
index c9af05b..89c905a 100644
--- a/src/load.c
+++ b/src/load.c
@@ -79,18 +79,18 @@
}
if (!cpio_get_file(cpio, &manifest_vm->kernel_filename, &kernel)) {
- dlog("Could not find kernel file \"%s\".\n",
- string_data(&manifest_vm->kernel_filename));
+ dlog_error("Could not find kernel file \"%s\".\n",
+ string_data(&manifest_vm->kernel_filename));
return false;
}
if (pa_difference(begin, end) < memiter_size(&kernel)) {
- dlog("Kernel is larger than available memory.\n");
+ dlog_error("Kernel is larger than available memory.\n");
return false;
}
if (!copy_to_unmapped(stage1_locked, begin, &kernel, ppool)) {
- dlog("Unable to copy kernel.\n");
+ dlog_error("Unable to copy kernel.\n");
return false;
}
@@ -134,17 +134,17 @@
if (!load_kernel(stage1_locked, primary_begin, primary_end, manifest_vm,
cpio, ppool)) {
- dlog("Unable to load primary kernel.");
+ dlog_error("Unable to load primary kernel.");
return false;
}
if (!vm_init_next(MAX_CPUS, ppool, &vm)) {
- dlog("Unable to initialise primary vm\n");
+ dlog_error("Unable to initialise primary vm\n");
return false;
}
if (vm->id != HF_PRIMARY_VM_ID) {
- dlog("Primary vm was not given correct id\n");
+ dlog_error("Primary vm was not given correct id\n");
return false;
}
@@ -164,7 +164,8 @@
if (!vm_identity_map(vm_locked, pa_init(0),
pa_init(UINT64_C(1024) * 1024 * 1024 * 1024),
MM_MODE_R | MM_MODE_W | MM_MODE_D, ppool, NULL)) {
- dlog("Unable to initialise address space for primary vm\n");
+ dlog_error(
+ "Unable to initialise address space for primary vm\n");
ret = false;
goto out;
}
@@ -175,20 +176,21 @@
params->mem_ranges[i].end,
MM_MODE_R | MM_MODE_W | MM_MODE_X, ppool,
NULL)) {
- dlog("Unable to initialise memory for primary vm\n");
+ dlog_error(
+ "Unable to initialise memory for primary vm\n");
ret = false;
goto out;
}
}
if (!vm_unmap_hypervisor(vm_locked, ppool)) {
- dlog("Unable to unmap hypervisor from primary vm\n");
+ dlog_error("Unable to unmap hypervisor from primary vm\n");
ret = false;
goto out;
}
if (!plat_iommu_unmap_iommus(vm_locked, ppool)) {
- dlog("Unable to unmap IOMMUs from primary VM\n");
+ dlog_error("Unable to unmap IOMMUs from primary VM\n");
ret = false;
goto out;
}
@@ -220,12 +222,12 @@
if (!load_kernel(stage1_locked, mem_begin, mem_end, manifest_vm, cpio,
ppool)) {
- dlog("Unable to load kernel.\n");
+ dlog_error("Unable to load kernel.\n");
return false;
}
if (!vm_init_next(manifest_vm->secondary.vcpu_count, ppool, &vm)) {
- dlog("Unable to initialise VM.\n");
+ dlog_error("Unable to initialise VM.\n");
return false;
}
@@ -239,13 +241,13 @@
if (!vm_identity_map(vm_locked, mem_begin, mem_end,
MM_MODE_R | MM_MODE_W | MM_MODE_X, ppool,
&secondary_entry)) {
- dlog("Unable to initialise memory.\n");
+ dlog_error("Unable to initialise memory.\n");
ret = false;
goto out;
}
- dlog("Loaded with %u vCPUs, entry at %#x.\n",
- manifest_vm->secondary.vcpu_count, pa_addr(mem_begin));
+ dlog_info("Loaded with %u vCPUs, entry at %#x.\n",
+ manifest_vm->secondary.vcpu_count, pa_addr(mem_begin));
vcpu = vm_get_vcpu(vm, 0);
vcpu_secondary_reset_and_start(vcpu, secondary_entry,
@@ -307,8 +309,9 @@
for (i = 0; i < mem_ranges_count; ++i) {
if (pa_addr(after[i].begin) > pa_addr(before[i].begin)) {
if (update->reserved_ranges_count >= MAX_MEM_RANGES) {
- dlog("Too many reserved ranges after loading "
- "secondary VMs.\n");
+ dlog_error(
+ "Too many reserved ranges after "
+ "loading secondary VMs.\n");
return false;
}
update->reserved_ranges[update->reserved_ranges_count]
@@ -319,8 +322,9 @@
}
if (pa_addr(after[i].end) < pa_addr(before[i].end)) {
if (update->reserved_ranges_count >= MAX_MEM_RANGES) {
- dlog("Too many reserved ranges after loading "
- "secondary VMs.\n");
+ dlog_error(
+ "Too many reserved ranges after "
+ "loading secondary VMs.\n");
return false;
}
update->reserved_ranges[update->reserved_ranges_count]
@@ -351,7 +355,7 @@
if (!load_primary(stage1_locked, &manifest->vm[HF_PRIMARY_VM_INDEX],
cpio, params, ppool)) {
- dlog("Unable to load primary VM.\n");
+ dlog_error("Unable to load primary VM.\n");
return false;
}
@@ -393,29 +397,31 @@
continue;
}
- dlog("Loading VM%d: %s.\n", (int)vm_id,
- manifest_vm->debug_name);
+ dlog_info("Loading VM%d: %s.\n", (int)vm_id,
+ manifest_vm->debug_name);
mem_size = align_up(manifest_vm->secondary.mem_size, PAGE_SIZE);
if (!carve_out_mem_range(mem_ranges_available,
params->mem_ranges_count, mem_size,
&secondary_mem_begin,
&secondary_mem_end)) {
- dlog("Not enough memory (%u bytes).\n", mem_size);
+ dlog_error("Not enough memory (%u bytes).\n", mem_size);
continue;
}
if (!load_secondary(stage1_locked, secondary_mem_begin,
secondary_mem_end, manifest_vm, cpio,
ppool)) {
- dlog("Unable to load VM.\n");
+ dlog_error("Unable to load VM.\n");
continue;
}
/* Deny the primary VM access to this memory. */
if (!vm_unmap(primary_vm_locked, secondary_mem_begin,
secondary_mem_end, ppool)) {
- dlog("Unable to unmap secondary VM from primary VM.\n");
+ dlog_error(
+ "Unable to unmap secondary VM from primary "
+ "VM.\n");
success = false;
break;
}
diff --git a/src/manifest.c b/src/manifest.c
index 93560c5..db01612 100644
--- a/src/manifest.c
+++ b/src/manifest.c
@@ -286,7 +286,7 @@
}
if (uint32list_has_next(&smcs)) {
- dlog("%s SMC whitelist too long.\n", vm->debug_name);
+ dlog_warning("%s SMC whitelist too long.\n", vm->debug_name);
}
TRY(read_bool(node, "smc_whitelist_permissive",
diff --git a/src/mm.c b/src/mm.c
index 83bf9bd..d66cce2 100644
--- a/src/mm.c
+++ b/src/mm.c
@@ -315,7 +315,7 @@
/* Allocate a new table. */
ntable = mm_alloc_page_tables(1, ppool);
if (ntable == NULL) {
- dlog("Failed to allocate memory for page table\n");
+ dlog_error("Failed to allocate memory for page table\n");
return NULL;
}
@@ -1024,15 +1024,15 @@
/* Locking is not enabled yet so fake it, */
struct mm_stage1_locked stage1_locked = mm_stage1_lock_unsafe();
- dlog("text: %#x - %#x\n", pa_addr(layout_text_begin()),
- pa_addr(layout_text_end()));
- dlog("rodata: %#x - %#x\n", pa_addr(layout_rodata_begin()),
- pa_addr(layout_rodata_end()));
- dlog("data: %#x - %#x\n", pa_addr(layout_data_begin()),
- pa_addr(layout_data_end()));
+ dlog_info("text: %#x - %#x\n", pa_addr(layout_text_begin()),
+ pa_addr(layout_text_end()));
+ dlog_info("rodata: %#x - %#x\n", pa_addr(layout_rodata_begin()),
+ pa_addr(layout_rodata_end()));
+ dlog_info("data: %#x - %#x\n", pa_addr(layout_data_begin()),
+ pa_addr(layout_data_end()));
if (!mm_ptable_init(&ptable, MM_FLAG_STAGE1, ppool)) {
- dlog("Unable to allocate memory for page table.\n");
+ dlog_error("Unable to allocate memory for page table.\n");
return false;
}
diff --git a/src/spci_architected_message.c b/src/spci_architected_message.c
index e9860bb..2dc2899 100644
--- a/src/spci_architected_message.c
+++ b/src/spci_architected_message.c
@@ -616,7 +616,7 @@
memory_to_attributes = MM_MODE_R | MM_MODE_W | MM_MODE_X;
break;
default:
- dlog("Invalid memory sharing message.\n");
+ dlog_error("Invalid memory sharing message.\n");
return spci_error(SPCI_INVALID_PARAMETERS);
}
diff --git a/src/vcpu.c b/src/vcpu.c
index 2f1b5fc..b77689d 100644
--- a/src/vcpu.c
+++ b/src/vcpu.c
@@ -164,10 +164,11 @@
sl_unlock(&vm->lock);
if (!resume) {
- dlog("Stage-2 page fault: pc=%#x, vmid=%u, vcpu=%u, "
- "vaddr=%#x, ipaddr=%#x, mode=%#x\n",
- f->pc, vm->id, vcpu_index(current), f->vaddr, f->ipaddr,
- f->mode);
+ dlog_warning(
+ "Stage-2 page fault: pc=%#x, vmid=%u, vcpu=%u, "
+ "vaddr=%#x, ipaddr=%#x, mode=%#x\n",
+ f->pc, vm->id, vcpu_index(current), f->vaddr, f->ipaddr,
+ f->mode);
}
return resume;
