cat /proc/sys/kernel/printk+
diff --git a/index.html b/index.html index 33348d9..61617e0 100644 --- a/index.html +++ b/index.html @@ -817,10 +817,11 @@ body.book #toc,body.book #preamble,body.book h1.sect0,body.book .sect1>h2{page-b
The debug highest level is a bit more magic, see: Section 15.4.2, “pr_debug” for more info.
+The debug highest level is a bit more magic, see: Section 15.4.3, “pr_debug” for more info.
The current printk level can be obtained with:
+cat /proc/sys/kernel/printk+
As of 87e846fc1f9c57840e143513ebd69c638bd37aa8 this prints:
7 4 1 7+
which contains:
+7: current log level, modifiable by previously mentioned methods
4: documented as: "printk’s without a loglevel use this": TODO what does that mean, how to call printk without a log level?
1: minimum log level that still prints something (0 prints nothing)
7: default log level
We start at the boot time default after boot by default, as can be seen from:
+insmod myprintk.ko+
which outputs something like:
+<1>[ 12.494429] pr_alert +<2>[ 12.494666] pr_crit +<3>[ 12.494823] pr_err +<4>[ 12.494911] pr_warning +<5>[ 12.495170] pr_notice +<6>[ 12.495327] pr_info+
Source: kernel_modules/myprintk.c
+This proc entry is defined at: https://github.com/torvalds/linux/blob/v5.1/kernel/sysctl.c#L839
+#if defined CONFIG_PRINTK
+ {
+ .procname = "printk",
+ .data = &console_loglevel,
+ .maxlen = 4*sizeof(int),
+ .mode = 0644,
+ .proc_handler = proc_dointvec,
+ },
+which teaches us that printk can be completely disabled at compile time:
+config PRINTK + default y + bool "Enable support for printk" if EXPERT + select IRQ_WORK + help + This option enables normal printk support. Removing it + eliminates most of the message strings from the kernel image + and makes the kernel more or less silent. As this makes it + very difficult to diagnose system problems, saying N here is + strongly discouraged.+
console_loglevel is defined at:
#define console_loglevel (console_printk[0])+
and console_printk is an array with 4 ints:
int console_printk[4] = {
+ CONSOLE_LOGLEVEL_DEFAULT, /* console_loglevel */
+ MESSAGE_LOGLEVEL_DEFAULT, /* default_message_loglevel */
+ CONSOLE_LOGLEVEL_MIN, /* minimum_console_loglevel */
+ CONSOLE_LOGLEVEL_DEFAULT, /* default_console_loglevel */
+};
+and then we see that the default is configurable with CONFIG_CONSOLE_LOGLEVEL_DEFAULT:
/* + * Default used to be hard-coded at 7, quiet used to be hardcoded at 4, + * we're now allowing both to be set from kernel config. + */ +#define CONSOLE_LOGLEVEL_DEFAULT CONFIG_CONSOLE_LOGLEVEL_DEFAULT +#define CONSOLE_LOGLEVEL_QUIET CONFIG_CONSOLE_LOGLEVEL_QUIET+
The message loglevel default is explained at:
+/* printk's without a loglevel use this.. */ +#define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT+
The min is just hardcoded to one as you would expect, with some amazing kernel comedy around it:
+/* We show everything that is MORE important than this.. */ +#define CONSOLE_LOGLEVEL_SILENT 0 /* Mum's the word */ +#define CONSOLE_LOGLEVEL_MIN 1 /* Minimum loglevel we let people use */ +#define CONSOLE_LOGLEVEL_DEBUG 10 /* issue debug messages */ +#define CONSOLE_LOGLEVEL_MOTORMOUTH 15 /* You can't shut this one up */+
We then also learn about the useless quiet and debug kernel parameters at:
config CONSOLE_LOGLEVEL_QUIET + int "quiet console loglevel (1-15)" + range 1 15 + default "4" + help + loglevel to use when "quiet" is passed on the kernel commandline. + + When "quiet" is passed on the kernel commandline this loglevel + will be used as the loglevel. IOW passing "quiet" will be the + equivalent of passing "loglevel=<CONSOLE_LOGLEVEL_QUIET>"+
which explains the useless reason why that number is special. This is implemented at:
+static int __init debug_kernel(char *str)
+{
+ console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+ return 0;
+}
+
+static int __init quiet_kernel(char *str)
+{
+ console_loglevel = CONSOLE_LOGLEVEL_QUIET;
+ return 0;
+}
+
+early_param("debug", debug_kernel);
+early_param("quiet", quiet_kernel);
+./run --kernel-cli 'ignore_loglevel'@@ -9887,7 +10082,7 @@ mount
Get ready for the noisiest boot ever, I think it overflows the printk buffer and funny things happen.
When CONFIG_DYNAMIC_DEBUG is set, printk(KERN_DEBUG is not the exact same as pr_debug( since printk(KERN_DEBUG messages are visible with:
According to ARMv7 architecture reference manual, access to that register is controlled by other registers NSACR.{CP11, CP10} and HCPTR so those must be turned off, but I’m lazy to investigate now, even just trying to dump those registers in userland/arch/arm/dump_regs.c also leads to exceptions…
TODO. Create a minimal runnable example of going into EL0 and jumping to EL1.
+See ARMv8 architecture reference manual db D1.6.2 "The stack pointer registers".
+TODO create a minimal runnable example.
+TODO: how to select to use SP0 in an exception handler?
+./run \ --arch aarch64 \ - --baremetal baremetal/arch/aarch64/svc_asm.S + --baremetal baremetal/arch/aarch64/svc.c \ -- -d in_asm,int \ ;
the output contains:
+the output at 8f73910dd1fc1fa6dc6904ae406b7598cdcd96d7 contains:
---------------- -IN: -0x40002060: d4000001 svc #0 +IN: main +0x40002098: d41579a1 svc #0xabcd Taking exception 2 [SVC] ...from EL1 to EL1 -...with ESR 0x15/0x56000000 -...with ELR 0x40002064 +...with ESR 0x15/0x5600abcd +...with ELR 0x4000209c ...to EL1 PC 0x40000a00 PSTATE 0x3c5 ---------------- IN: -0x40000a00: 14000225 b #0x40001294+0x40000a00: 14000225 b #0x40001294 + +---------------- +IN: +0x40001294: a9bf7bfd stp x29, x30, [sp, #-0x10]! +0x40001298: a9bf73fb stp x27, x28, [sp, #-0x10]! +0x4000129c: a9bf6bf9 stp x25, x26, [sp, #-0x10]! +0x400012a0: a9bf63f7 stp x23, x24, [sp, #-0x10]! +0x400012a4: a9bf5bf5 stp x21, x22, [sp, #-0x10]! +0x400012a8: a9bf53f3 stp x19, x20, [sp, #-0x10]! +0x400012ac: a9bf4bf1 stp x17, x18, [sp, #-0x10]! +0x400012b0: a9bf43ef stp x15, x16, [sp, #-0x10]! +0x400012b4: a9bf3bed stp x13, x14, [sp, #-0x10]! +0x400012b8: a9bf33eb stp x11, x12, [sp, #-0x10]! +0x400012bc: a9bf2be9 stp x9, x10, [sp, #-0x10]! +0x400012c0: a9bf23e7 stp x7, x8, [sp, #-0x10]! +0x400012c4: a9bf1be5 stp x5, x6, [sp, #-0x10]! +0x400012c8: a9bf13e3 stp x3, x4, [sp, #-0x10]! +0x400012cc: a9bf0be1 stp x1, x2, [sp, #-0x10]! +0x400012d0: d5384015 mrs x21, spsr_el1 +0x400012d4: a9bf03f5 stp x21, x0, [sp, #-0x10]! +0x400012d8: d5384035 mrs x21, elr_el1 +0x400012dc: a9bf57ff stp xzr, x21, [sp, #-0x10]! +0x400012e0: d2800235 movz x21, #0x11 +0x400012e4: d5385216 mrs x22, esr_el1 +0x400012e8: a9bf5bf5 stp x21, x22, [sp, #-0x10]! +0x400012ec: 910003f5 mov x21, sp +0x400012f0: 910482b5 add x21, x21, #0x120 +0x400012f4: f9000bf5 str x21, [sp, #0x10] +0x400012f8: 910003e0 mov x0, sp +0x400012fc: 9400023f bl #0x40001bf8 + +---------------- +IN: lkmc_vector_trap_handler +0x40001bf8: a9bd7bfd stp x29, x30, [sp, #-0x30]!
So we see in both cases that the SVC is done, then an exception happens, and then we just continue running from the exception handler address.
+So we see in both cases that the:
+SVC is done
+an exception happens, and the PC jumps to address 0x40000a00. From our custom terminal prints further on, we see that this equals VBAR_EL1 + 0x200.
According to the format of the ARMv8 exception vector table format, we see that the + 0x200 means that we are jumping in the Current EL with SPx.
The vector table format is described on ARMv8 architecture reference manual Table D1-7 "Vector offsets from vector table base address".
+This can also be deduced from the message exc_type is LKMC_VECTOR_SYNC_SPX: we just manually store a different integer for every exception vector type in our handler code to be able to tell what happened.
A good representation of the format of the vector table can also be found at Programmer’s Guide for ARMv8-A Table 10-2 "Vector table offsets from vector table base address".
+This is the one used because we are jumping from EL1 to EL1.
The first part of the table contains: Table 6, “Summary of ARMv8 vector handlers”.
+We set VBAR_EL1 to that address ourselves in the bootloader.
| Address | -Exception type | -Description | -
|---|---|---|
VBAR_ELn + 0x000 |
-Synchronous |
-Current EL with SP0 |
-
VBAR_ELn + 0x080 |
-IRQ/vIRQ + 0x100 |
-Current EL with SP0 |
-
VBAR_ELn + 0x100 |
-FIQ/vFIQ |
-Current EL with SP0 |
-
VBAR_ELn + 0x180 |
-SError/vSError |
-Current EL with SP0 |
-
at 0x40000a00 a b #0x40001294 is done and then at 0x40001294 boilerplate preparation is done for lkmc_vector_trap_handler starting with several STP instructions.
and the following other parts are analogous, but referring to SPx and lower ELs.
+We have coded both of those in our vector table macro madness. As of LKMC 8f73910dd1fc1fa6dc6904ae406b7598cdcd96d7, both come from lkmc/aarch64.h:
+b #0x40001294 comes from: LKMC_VECTOR_ENTRY
the STP come from: LKMC_VECTOR_BUILD_TRAPFRAME
We jump immediately from inside LKMC_VECTOR_ENTRY to LKMC_VECTOR_BUILD_TRAPFRAME because we can only use 0x80 bytes of instructions for each one before reaching the next handler, so we might as well get it over with by jumping into a memory region without those constraints.
We are going to do everything in EL1 for now.
+TODO: why doesn’t QEMU show our nice symbol names? gem5 shows them fine, and nm says they are there!
0000000040000800 T lkmc_vector_table +0000000040001294 T lkmc_vector_build_trapframe_curr_el_spx_sync+
The exception return happens at the end of lkmc_vector_trap_handler:
---------------- +IN: lkmc_vector_trap_handler +0x40002000: d503201f nop +0x40002004: a8c37bfd ldp x29, x30, [sp], #0x30 +0x40002008: d65f03c0 ret + +---------------- +IN: +0x40001300: 910043ff add sp, sp, #0x10 +0x40001304: a8c15bf5 ldp x21, x22, [sp], #0x10 +0x40001308: d5184036 msr elr_el1, x22 + +---------------- +IN: +0x4000130c: a8c103f5 ldp x21, x0, [sp], #0x10 +0x40001310: d5184015 msr spsr_el1, x21 + +---------------- +IN: +0x40001314: a8c10be1 ldp x1, x2, [sp], #0x10 +0x40001318: a8c113e3 ldp x3, x4, [sp], #0x10 +0x4000131c: a8c11be5 ldp x5, x6, [sp], #0x10 +0x40001320: a8c123e7 ldp x7, x8, [sp], #0x10 +0x40001324: a8c12be9 ldp x9, x10, [sp], #0x10 +0x40001328: a8c133eb ldp x11, x12, [sp], #0x10 +0x4000132c: a8c13bed ldp x13, x14, [sp], #0x10 +0x40001330: a8c143ef ldp x15, x16, [sp], #0x10 +0x40001334: a8c14bf1 ldp x17, x18, [sp], #0x10 +0x40001338: a8c153f3 ldp x19, x20, [sp], #0x10 +0x4000133c: a8c15bf5 ldp x21, x22, [sp], #0x10 +0x40001340: a8c163f7 ldp x23, x24, [sp], #0x10 +0x40001344: a8c16bf9 ldp x25, x26, [sp], #0x10 +0x40001348: a8c173fb ldp x27, x28, [sp], #0x10 +0x4000134c: a8c17bfd ldp x29, x30, [sp], #0x10 +0x40001350: d69f03e0 eret + +Exception return from AArch64 EL1 to AArch64 EL1 PC 0x4000209c +---------------- +IN: main +0x4000209c: d0000040 adrp x0, #0x4000c000+
which does an eret and jumps back to 0x4000209c, which is 4 bytes and therefore one instruction after where SVC was taken at 0x40002098.
In QEMU, and then we just continue running from the exception handler address.
On the terminal output, we observe the initial values of:
@@ -26179,7 +26477,147 @@ IN:The vector table format is described on ARMv8 architecture reference manual Table D1-7 "Vector offsets from vector table base address".
+A good representation of the format of the vector table can also be found at Programmer’s Guide for ARMv8-A Table 10-2 "Vector table offsets from vector table base address".
+The first part of the table contains: Table 6, “Summary of ARMv8 vector handlers”.
+| Address | +Exception type | +Description | +
|---|---|---|
VBAR_ELn + 0x000 |
+Synchronous |
+Current EL with SP0 |
+
VBAR_ELn + 0x080 |
+IRQ/vIRQ |
+Current EL with SP0 |
+
VBAR_ELn + 0x100 |
+FIQ/vFIQ |
+Current EL with SP0 |
+
VBAR_ELn + 0x180 |
+SError/vSError |
+Current EL with SP0 |
+
VBAR_ELn + 0x200 |
+Synchronous |
+Current EL with SPx |
+
VBAR_ELn + 0x280 |
+IRQ/vIRQ |
+Current EL with SPx |
+
VBAR_ELn + 0x300 |
+FIQ/vFIQ |
+Current EL with SPx |
+
VBAR_ELn + 0x380 |
+SError/vSError |
+Lower EL using AArch64 |
+
VBAR_ELn + 0x400 |
+Synchronous |
+Lower EL using AArch64 |
+
VBAR_ELn + 0x480 |
+IRQ/vIRQ |
+Lower EL using AArch64 |
+
VBAR_ELn + 0x500 |
+FIQ/vFIQ |
+Lower EL using AArch64 |
+
VBAR_ELn + 0x580 |
+SError/vSError |
+Lower EL using AArch64 |
+
VBAR_ELn + 0x600 |
+Synchronous |
+Lower EL using AArch32 |
+
VBAR_ELn + 0x680 |
+IRQ/vIRQ |
+Lower EL using AArch32 |
+
VBAR_ELn + 0x700 |
+FIQ/vFIQ |
+Lower EL using AArch32 |
+
VBAR_ELn + 0x780 |
+SError/vSError |
+Lower EL using AArch32 |
+
and the following other parts are analogous, but referring to SPx and lower ELs.
+Now, to fully understand this table, we need the following concepts:
+Synchronous: what happens for example when we do an ARM SVC instruction.
+It is called synchronous because the CPU is generating it itself from an instruction, unlike an interrupt generated by a device like a keyboard, which ends up in an IRQ or FIQ
+IRQ: an example can be found at: ARM timer
+TODO FIQ vs IRQ
+TODO SError
+EL changes: ARM change exception level
+SP0 vs SPx: ARM SP0 vs SPx.
+Exception Syndrome Register.
Exception Link Register.
CNTFRQ_EL0: "Counter-timer Frequency register". "Indicates the system counter clock frequency, in Hz."
CNTV_CTL_EL0: "Counter-timer Virtual Timer Control register"
CNTV_CTL_EL0: "Counter-timer Virtual Timer Control register". This control register is very simple and only has three fields:
CNTV_CTL_EL0.ISTATUS bit: set to 1 when the timer condition is met
CNTV_CTL_EL0.IMASK bit: if 1, the interrupt does not happen when ISTATUS becomes one
CNTV_CTL_EL0.ENABLE bit: if 0, the counter is turned off, interrupts don’t happen
CNTV_CVAL_EL0: "Counter-timer Virtual Timer CompareValue register". The interrupt happens when CNTVCT_EL0 reaches the value in this register.
Generic Interrupt Controller.
+Examples:
+ARM publishes both a GIC standard architecture specification, and specific implementations of these specifications.
+The specification can be found at: https://developer.arm.com/docs/ihi0069/latest
+As of 2019Q2 the latest version if v4.0, often called GICv4: https://static.docs.arm.com/ihi0069/e/Q1-IHI0069E_gic_architecture_specification_v3.1_19_01_21.pdf
+That document clarifies that GICv2 is a legacy specification only:
+Version 2.0 (GICv2) is only described in terms of the GICv3 optional support for legacy operation+
The specific models have names of type GIC-600, GIC-500, etc.
+TODO create a minimal working aarch64 example analogous to the x86 one at: https://github.com/cirosantilli/x86-bare-metal-examples/blob/6dc9a73830fc05358d8d66128f740ef9906f7677/paging.S
First, also consider the userland bibliography: Section 23.8, “ARM assembly bibliography”.
which tries to write to 0x8010000 according to GDB.
Without -machine, QEMU’s DTB clearly states GICv2, so I’m starting to wonder if Nienfeng just made a mistake there? The QEMU GICv3 dtb contains:
Without -machine, QEMU’s DTB clearly states GICv2, so I’m starting to wonder if Nienfeng just made a mistake there? The QEMU GICv3 DTB contains:
but it entered an exception loop at MSR CPTR_EL3, XZR.
We then found out that QEMU <starts in EL1, and so we kept just the EL1 part, and it worked. Related:
+We then found out that QEMU starts in EL1, and so we kept just the EL1 part, and it worked. Related: