From 6c02057cc5aaf5433c1e302e7a1a36e4fa4a8f95 Mon Sep 17 00:00:00 2001 From: Rodrigo Arias Mallo Date: Fri, 4 Oct 2024 09:01:41 +0200 Subject: [PATCH] Update JOURNAL --- JOURNAL.md | 798 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 798 insertions(+) diff --git a/JOURNAL.md b/JOURNAL.md index 2ca183d..e7e8668 100644 --- a/JOURNAL.md +++ b/JOURNAL.md @@ -4342,3 +4342,801 @@ It works, but very slowly: Let's add the ability to claim a context in the plictool, as I suspect the claim may be broken. + +## 2024-10-02 + +Interesting output with ftrace: + + + <<< NixOS Stage 1 >>> + + + An error occurred in stage 1 of the boot process, which must mount the + root filesystem on `/mnt-root' and then start stage 2. Press one + of the following keys: + + i) to launch an interactive shell + f) to start an interactive shell having pid 1 (needed if you want to + start stage 2's init manually) + r) to reboot immediately + *) to ignore the error and continue + iStarting interactive shell... + ~ # mount -t tracefs nodev /sys/kernel/tracing/ + ~ # cd /sys/kernel/tracing/ + /sys/kernel/tracing # cat current_tracer + function + /sys/kernel/tracing # cat enabled_functions + plic_irq_unmask (1) + plic_irq_mask (1) + plic_dying_cpu (1) + plic_starting_cpu (1) + plic_irq_domain_translate (1) + plic_irq_domain_alloc (1) + plic_parse_context_parent (1) + plic_irq_set_type (1) + plic_toggle.constprop.0 (1) + plic_irq_eoi (1) + plic_probe (1) + plic_irq_suspend (1) + plic_handle_irq (1) + plic_irq_enable (1) + plic_irq_disable (1) + plic_irq_resume (1) + /sys/kernel/tracing # cat tracing_on + 1 + /sys/kernel/tracing # cat trac + trace trace_options tracing_max_latency + trace_clock trace_pipe tracing_on + trace_marker trace_stat/ tracing_thresh + trace_marker_raw tracing_cpumask + /sys/kernel/tracing # cat trace + # tracer: function + # + # entries-in-buffer/entries-written: 1586/1586 #P:1 + ... + /sys/kernel/tracing # cat options/function-trace + 1 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 - 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # cat tracing_on + 1 + /sys/kernel/tracing # echo 0>tracing_on + + /sys/kernel/tracing # cat tracing_on + 1 + /sys/kernel/tracing # echo 0 > tracing_on + /sys/kernel/tracing # cat tracing_on + 0 + /sys/kernel/tracing # echo plic_handle_irq > set_ftrace_filter + /sys/kernel/tracing # cat enabled_functions + plic_handle_irq (1) + /sys/kernel/tracing # echo plic_handle_irq,plic_irq_eoi,plic_irq_enable,plic_irq + _disable > set_ftrace_filter ^C + + /sys/kernel/tracing # echo plic_irq_eoi >> set_ftrace_filter + /sys/kernel/tracing # cat enabled_functions + plic_irq_eoi (1) + plic_handle_irq (1) + /sys/kernel/tracing # echo plic_irq_enable >> set_ftrace_filter + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 - 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # ^Ct enabled_functions + + /sys/kernel/tracing # echo hi > /dev/ttyS1 + ^Z^C + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # echo plic_irq_enable >> set_f^Cace_filter + + /sys/kernel/tracing # cat tracing_on + 0 + /sys/kernel/tracing # echo 1 > tracing_on + /sys/kernel/tracing # cat tracing_on + 1 + /sys/kernel/tracing # cat trace_pipe & + /sys/kernel/tracing # fg + cat trace_pipe + ^Z[1]+ Stopped cat trace_pipe + /sys/kernel/tracing # bg + [1] cat trace_pipe + /sys/kernel/tracing # echo hi > /dev/ttyS1 + ash-91 [000] d..2. 669.966205: plic_irq_enable <-irq_enable + ash-91 [000] d..2. 669.966815: plic_irq_enable <-irq_enable + + *** local echo: yes *** + + *** local echo: no *** + ^C + /sys/kernel/tracing # echo 0 > tracing_on + /sys/kernel/tracing # cat tracing_on + 0 + /sys/kernel/tracing # echo 'plic_*' >> set_ftrace_filter + /sys/kernel/tracing # cat enabled_functions + plic_irq_unmask (1) + plic_irq_mask (1) + plic_dying_cpu (1) + plic_starting_cpu (1) + plic_irq_domain_translate (1) + plic_irq_domain_alloc (1) + plic_parse_context_parent (1) + plic_irq_set_type (1) + plic_toggle.constprop.0 (1) + plic_irq_eoi (1) + plic_probe (1) + plic_irq_suspend (1) + plic_handle_irq (1) + plic_irq_enable (1) + plic_irq_disable (1) + plic_irq_resume (1) + /sys/kernel/tracing # echo 1 > tracing_on + /sys/kernel/tracing # cat trace_pipe & + /sys/kernel/tracing # cat: can't open 'trace_pipe': Device or resource busy + + [2]+ Done(1) cat trace_pipe + /sys/kernel/tracing # ps + PID USER TIME COMMAND + 1 0 0:33 {init} /nix/store/y477q6jlbg9b53knnclgib65fbzpazkj-extra-u + 2 0 0:00 [kthreadd] + 3 0 0:00 [pool_workqueue_] + 4 0 0:00 [kworker/R-slub_] + 5 0 0:00 [kworker/R-netns] + 6 0 0:00 [kworker/0:0-eve] + 7 0 0:00 [kworker/0:0H] + 8 0 0:03 [kworker/u4:0-ev] + 9 0 0:00 [kworker/R-mm_pe] + 10 0 0:41 [kworker/u4:1-ev] + 11 0 0:00 [rcu_tasks_rude_] + 12 0 0:00 [rcu_tasks_trace] + 13 0 0:00 [ksoftirqd/0] + 14 0 0:00 [kworker/0:1-eve] + 15 0 0:01 [kdevtmpfs] + 16 0 0:00 [kworker/R-inet_] + 17 0 0:00 [kauditd] + 18 0 0:00 [khungtaskd] + 20 0 0:00 [oom_reaper] + 21 0 0:00 [kworker/R-write] + 22 0 0:01 [kcompactd0] + 23 0 0:00 [ksmd] + 24 0 0:00 [kworker/R-kinte] + 25 0 0:00 [kworker/R-kbloc] + 26 0 0:00 [kworker/R-blkcg] + 27 0 0:00 [kworker/R-ata_s] + 28 0 0:00 [kworker/R-devfr] + 29 0 0:00 [watchdogd] + 30 0 0:01 [kworker/u4:3-ev] + 31 0 0:00 [kworker/R-rpcio] + 32 0 0:00 [kworker/R-xprti] + 33 0 0:00 [kswapd0] + 34 0 0:00 [kworker/R-nfsio] + 35 0 0:00 [kworker/R-kthro] + 36 0 0:09 [khvcd] + 37 0 0:00 [kworker/R-uas] + 38 0 0:00 [kworker/R-mld] + 39 0 0:00 [kworker/R-ipv6_] + 46 0 0:00 [kworker/R-kstrp] + 47 0 0:00 [kworker/u5:0] + 73 0 0:00 tee -i /proc/self/fd/8 + 74 0 0:00 {init} /nix/store/y477q6jlbg9b53knnclgib65fbzpazkj-extra-u + 91 0 0:46 /nix/store/y477q6jlbg9b53knnclgib65fbzpazkj-extra-utils/bi + 113 0 0:00 cat trace_pipe + 117 0 0:00 ps + /sys/kernel/tracing # fg + cat trace_pipe + ^C + /sys/kernel/tracing # cat trace_pipe & + /sys/kernel/tracing # echo 1 > tracing_on + /sys/kernel/tracing # echo hi > /dev/ttyS1 + ash-91 [000] d..2. 748.552248: plic_irq_enable <-irq_enable + ash-91 [000] d..2. 748.552370: plic_toggle.constprop.0 <-plic_irq_enable + ash-91 [000] d..2. 748.552797: plic_irq_disable <-irq_disable + ash-91 [000] d..2. 748.552858: plic_toggle.constprop.0 <-plic_irq_disable + ash-91 [000] d..2. 748.553102: plic_irq_enable <-irq_enable + ash-91 [000] d..2. 748.553163: plic_toggle.constprop.0 <-plic_irq_enable + ^C + /sys/kernel/tracing # ash-91 [000] d..2. 762.013481: plic_irq_disable <-__irq_disable + ash-91 [000] d..2. 762.013603: plic_toggle.constprop.0 <-plic_irq_disable + + /sys/kernel/tracing # + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # plictool -C 1 + 0 + /sys/kernel/tracing # plictool -C 1 -w 4 + /sys/kernel/tracing # plictool -C 1 + 0 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # devmem 0x40014000 32 0xffffffff + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # plictool -C 1 -w 4 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # plictool -E + plictool: option requires an argument: E + plictool v0.0.5 -- Rodrigo Arias Mallo + Usage: + plictool [-a addr] [-L] [-n nsrc] [-x nctx] # List (default) + plictool [-a addr] -C ctx [-w value] # Claim + plictool [-a addr] -T ctx [-w value] # Threshold + plictool [-a addr] -I src [-w value] # Priority + plictool [-a addr] -P src [-w value] # Pending + plictool [-a addr] -E src -c ctx [-w value] # Enabled + plictool -v # Version + /sys/kernel/tracing # plictool -E 4 -c 0 -w 1 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 masked - + 36 - 0 masked - + /sys/kernel/tracing # plictool -C 0 + 4 + /sys/kernel/tracing # plictool -C 0 -w 4 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 - 1 masked - + 36 - 0 masked - + /sys/kernel/tracing # plictool -E 4 -c 0 -w 0 + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 - 1 - - + /sys/kernel/tracing # cat /dev/ttyS1 & + /sys/kernel/tracing # cat-136 [000] d..2. 887.106509: plic_irq_enable <-irq_enable + cat-136 [000] d..2. 887.106631: plic_toggle.constprop.0 <-plic_irq_enable + cat-136 [000] d.h2. 887.106814: plic_handle_irq <-generic_handle_domain_irq + cat-136 [000] d.h3. 887.106997: plic_irq_eoi <-handle_fasteoi_irq + cat-136 [000] d..2. 887.107424: plic_irq_disable <-irq_disable + cat-136 [000] d..2. 887.107546: plic_toggle.constprop.0 <-plic_irq_disable + cat-136 [000] d..2. 887.107729: plic_irq_enable <-irq_enable + cat-136 [000] d..2. 887.107790: plic_toggle.constprop.0 <-plic_irq_enable + + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - firing + 2 - 1 - - + 3 - 1 - - + 4 - 1 - - + 33 - 0 - masked + +So, then an interrupt is fired, we disable the interrupts and then we enable +them again. Can this happen because the next interrupt fired when interrupts +were disabled? + +There are also other cases in which we already have an interrupt pending and we +enable the context 1. For example, by setting the enable bit, changing the prio, +or the threshold for that context or by removing the context 0 enable bit. + +I think I can do some tests with those. I'm not sure why the serial port is +firing an interrupt, but if this is the case, I can try to write a character in +the transmit register and wait for the pending bit, then try to claim the +interrupt for source 1. + +## 2024-10-03 + + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + /sys/kernel/tracing # cat tracing_on + 1 + /sys/kernel/tracing # echo 0 > tracing_on + /sys/kernel/tracing # echo 1 > tracing_on + /sys/kernel/tracing # cat trace_pipe & + /sys/kernel/tracing # cat /dev/ttyS1 & + /sys/kernel/tracing # cat-122 [000] ...1. 2978.202587: serial8250_pm <-uart_port_startup + cat-122 [000] ...1. 2978.202648: serial8250_set_sleep <-serial8250_pm + cat-122 [000] ...1. 2978.202892: serial8250_startup <-uart_port_startup + cat-122 [000] ...1. 2978.203014: serial8250_do_startup <-serial8250_startup + cat-122 [000] d..2. 2978.203319: plic_irq_enable <-irq_enable + cat-122 [000] d..2. 2978.203380: plic_toggle.constprop.0 <-plic_irq_enable + cat-122 [000] d.h2. 2978.203563: plic_handle_irq <-generic_handle_domain_irq + cat-122 [000] d.h2. 2978.203685: serial8250_interrupt <-__handle_irq_event_percpu + cat-122 [000] d.h3. 2978.203746: serial8250_default_handle_irq <-serial8250_interrupt + cat-122 [000] d.h3. 2978.203807: serial8250_handle_irq <-serial8250_default_handle_irq + cat-122 [000] d.h3. 2978.203990: plic_irq_eoi <-handle_fasteoi_irq + cat-122 [000] d..2. 2978.204783: plic_irq_disable <-irq_disable + cat-122 [000] d..2. 2978.204844: plic_toggle.constprop.0 <-plic_irq_disable + cat-122 [000] d..2. 2978.205088: plic_irq_enable <-irq_enable + cat-122 [000] d..2. 2978.205149: plic_toggle.constprop.0 <-plic_irq_enable + cat-122 [000] d..2. 2978.205271: serial8250_do_set_mctrl <-serial8250_do_startup + cat-122 [000] ...1. 2978.205393: serial8250_set_termios <-uart_change_line_settings + cat-122 [000] ...1. 2978.206796: serial8250_do_set_termios <-serial8250_set_termios + cat-122 [000] .n.1. 2978.206918: serial8250_get_divisor <-serial8250_do_set_termios + cat-122 [000] dn.2. 2978.207040: serial8250_do_set_divisor <-serial8250_do_set_termios + cat-122 [000] dn.2. 2978.207101: serial8250_do_set_mctrl <-serial8250_do_set_termios + cat-122 [000] dn.2. 2978.207345: serial8250_set_mctrl <-uart_update_mctrl + cat-122 [000] dn.2. 2978.207406: serial8250_do_set_mctrl <-serial8250_set_mctrl + + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - firing + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + 33 - 0 - masked + /sys/kernel/tracing # plictool -C 1 + 0 + +Another test tracing the UART serial too. + +It would be nice to see where those calls are coming from. + +Let's collect the commands I need to use here: + + mount -t tracefs nodev /sys/kernel/tracing/ + cd /sys/kernel/tracing/ + echo 'plic_*' >> set_ftrace_filter + echo 'serial8250_*' >> set_ftrace_filter + cat current_tracer + +Here is a trace with the stack trace printed: + + ~ # plictool + Source Pend Prio C0(7) C1(0) + 1 - 1 - - + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + + ~ # + [...] + /sys/kernel/tracing # cat /dev/ttyS1 & + + cat-122 [000] ..... 591.693894: serial8250_pm <-uart_port_startup + cat-122 [000] ..... 591.694077: + => ftrace_call + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] ..... 591.694138: serial8250_set_sleep <-serial8250_pm + cat-122 [000] ..... 591.694260: + => ftrace_call + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] ..... 591.694504: serial8250_startup <-uart_port_startup + cat-122 [000] ..... 591.694687: + => ftrace_call + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] ..... 591.694748: serial8250_do_startup <-serial8250_startup + cat-122 [000] ..... 591.694870: + => ftrace_call + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.695236: plic_irq_enable <-irq_enable + cat-122 [000] d..1. 591.695358: + => ftrace_call + => irq_startup + => __setup_irq + => request_threaded_irq + => univ8250_setup_irq + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.695480: plic_toggle.constprop.0 <-plic_irq_enable + cat-122 [000] d..1. 591.695602: + => ftrace_call + => irq_enable + => irq_startup + => __setup_irq + => request_threaded_irq + => univ8250_setup_irq + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.696456: plic_irq_disable <-irq_disable + cat-122 [000] d..1. 591.696578: + => ftrace_call + => __disable_irq_nosync + => disable_irq_nosync + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.696639: plic_toggle.constprop.0 <-plic_irq_disable + cat-122 [000] d..1. 591.696822: + => ftrace_call + => irq_disable + => __disable_irq_nosync + => disable_irq_nosync + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.697005: plic_irq_enable <-irq_enable + cat-122 [000] d..1. 591.697188: + => ftrace_call + => irq_startup + => __enable_irq + => enable_irq + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d..1. 591.697249: plic_toggle.constprop.0 <-plic_irq_enable + cat-122 [000] d..1. 591.697432: + => ftrace_call + => irq_enable + => irq_startup + => __enable_irq + => enable_irq + => serial8250_do_startup + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] d.h1. 591.697554: plic_handle_irq <-generic_handle_domain_irq + cat-122 [000] d.h1. 591.697676: + => ftrace_call + => riscv_intc_irq + => handle_riscv_irq + => call_on_irq_stack + => 0x1c003b9260 + cat-122 [000] d.h1. 591.697798: serial8250_interrupt <-__handle_irq_event_percpu + cat-122 [000] d.h1. 591.697920: + => ftrace_call + => handle_irq_event + => handle_fasteoi_irq + => generic_handle_domain_irq + => plic_handle_irq + => generic_handle_domain_irq + => riscv_intc_irq + => handle_riscv_irq + => call_on_irq_stack + => 0x1c001dc940 + cat-122 [000] d.h2. 591.697981: serial8250_default_handle_irq <-serial8250_interrupt + cat-122 [000] d.h2. 591.698103: + => ftrace_call + => __handle_irq_event_percpu + => handle_irq_event + => handle_fasteoi_irq + => generic_handle_domain_irq + => plic_handle_irq + => generic_handle_domain_irq + => riscv_intc_irq + => handle_riscv_irq + => call_on_irq_stack + => 0x1c001dc940 + cat-122 [000] d.h2. 591.698164: serial8250_handle_irq <-serial8250_default_handle_irq + cat-122 [000] d.h2. 591.698286: + => ftrace_call + => serial8250_interrupt + => __handle_irq_event_percpu + => handle_irq_event + => handle_fasteoi_irq + => generic_handle_domain_irq + => plic_handle_irq + => generic_handle_domain_irq + => riscv_intc_irq + => handle_riscv_irq + => call_on_irq_stack + => 0x1c00595ba0 + cat-122 [000] d.h2. 591.698469: plic_irq_eoi <-handle_fasteoi_irq + cat-122 [000] d.h2. 591.698530: + => ftrace_call + => generic_handle_domain_irq + => plic_handle_irq + => generic_handle_domain_irq + => riscv_intc_irq + => handle_riscv_irq + => call_on_irq_stack + => 0x1c00595ba0 + cat-122 [000] d..1. 591.698713: serial8250_do_set_mctrl <-serial8250_do_startup + cat-122 [000] d..1. 591.698835: + => ftrace_call + => serial8250_startup + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] .n... 591.700177: serial8250_set_termios <-uart_change_line_settings + cat-122 [000] .n... 591.700299: + => ftrace_call + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] .n... 591.700421: serial8250_do_set_termios <-serial8250_set_termios + cat-122 [000] .n... 591.700543: + => ftrace_call + => uart_change_line_settings + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] .n... 591.700604: serial8250_get_divisor <-serial8250_do_set_termios + cat-122 [000] .n... 591.700787: + => ftrace_call + => serial8250_set_termios + => uart_change_line_settings + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] dn.1. 591.700909: serial8250_do_set_divisor <-serial8250_do_set_termios + cat-122 [000] dn.1. 591.701031: + => ftrace_call + => serial8250_set_termios + => uart_change_line_settings + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] dn.1. 591.701092: serial8250_do_set_mctrl <-serial8250_do_set_termios + cat-122 [000] dn.1. 591.701214: + => ftrace_call + => serial8250_set_termios + => uart_change_line_settings + => uart_port_startup + => uart_port_activate + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] dn.1. 591.701458: serial8250_set_mctrl <-uart_update_mctrl + cat-122 [000] dn.1. 591.701580: + => ftrace_call + => uart_dtr_rts + => tty_port_block_til_ready + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + cat-122 [000] dn.1. 591.701702: serial8250_do_set_mctrl <-serial8250_set_mctrl + cat-122 [000] dn.1. 591.701885: + => ftrace_call + => uart_update_mctrl + => uart_dtr_rts + => tty_port_block_til_ready + => tty_port_open + => uart_open + => tty_open + => chrdev_open + => do_dentry_open + => vfs_open + => path_openat + => do_filp_open + => do_sys_openat2 + => __riscv_sys_openat + => do_trap_ecall_u + => ret_from_exception + + /sys/kernel/tracing # plictool + Source Pend Prio C0(7) C1(0) + 1 yes 1 - firing + 2 - 1 - - + 3 - 1 - - + 4 yes 1 - - + 33 - 0 - masked + + /sys/kernel/tracing # plictool -C 1 + 0 + +## 2024-10-04 + +To trace which accesses are done to the PLIC, I can use the mmiotracer, which +will hopefully record how we configure the PLIC and lead to a reproducer. + + CONFIG_MMIOTRACE=y