Update JOURNAL

This commit is contained in:
Rodrigo Arias 2024-10-04 09:01:41 +02:00
parent f8886b28dd
commit 6c02057cc5

View File

@ -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 <rodrigo.arias@bsc.es>
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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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: <stack trace>
=> 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