Hello!
Enabled ftrace startup tests on a sparc64 test VM/LDOM:
$ diff -u <(gzip -dc ~/dmesg/config-5.10.0.gz) <(gzip -dc /proc/config.gz)
--- /dev/fd/63 2020-12-14 16:19:38.239372599 +0300
+++ /dev/fd/62 2020-12-14 16:19:38.235372433 +0300
@@ -2842,7 +2842,10 @@
# CONFIG_TRACEPOINT_BENCHMARK is not set
# CONFIG_RING_BUFFER_BENCHMARK is not set
# CONFIG_TRACE_EVAL_MAP_FILE is not set
-# CONFIG_FTRACE_STARTUP_TEST is not set
+CONFIG_FTRACE_SELFTEST=y
+CONFIG_FTRACE_STARTUP_TEST=y
+CONFIG_EVENT_TRACE_STARTUP_TEST=y
+# CONFIG_EVENT_TRACE_TEST_SYSCALLS is not set
# CONFIG_RING_BUFFER_STARTUP_TEST is not set
# CONFIG_PREEMPTIRQ_DELAY_TEST is not set
# CONFIG_KPROBE_EVENT_GEN_TEST is not set
Got the following results with kernel boot logs:
Dec 14 13:48:15 kernel: clocksource: jiffies: mask: 0xffffffff
max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Dec 14 13:48:15 kernel: futex hash table entries: 65536 (order: 9,
4194304 bytes, linear)
Dec 14 13:48:15 kernel: Running postponed tracer tests:
Dec 14 13:48:15 kernel: Testing tracer function:
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
trace_function+0x40/0x140
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
trace_function+0x44/0x140
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
trace_function+0x40/0x140
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
trace_function+0x44/0x140
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
trace_function+0x40/0x140
Dec 14 13:48:15 kernel: PASSED
Dec 14 13:48:15 kernel: Testing dynamic ftrace: PASSED
...
Dec 14 13:48:15 kernel: Testing event workqueue_execute_end:
Dec 14 13:48:15 kernel: log_unaligned: 194175 callbacks suppressed
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[47faa4]
trace_event_raw_event_workqueue_execute_end+0x44/0xa0
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[47fab0]
trace_event_raw_event_workqueue_execute_end+0x50/0xa0
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[47faa4]
trace_event_raw_event_workqueue_execute_end+0x44/0xa0
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[47fab0]
trace_event_raw_event_workqueue_execute_end+0x50/0xa0
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[47faa4]
trace_event_raw_event_workqueue_execute_end+0x44/0xa0
Dec 14 13:48:15 kernel: OK
...
Dec 14 13:48:15 kernel: Testing event sched_waking: OK
Dec 14 13:48:15 kernel: Testing event sched_kthread_stop_ret:
Dec 14 13:48:15 kernel: log_unaligned: 401755 callbacks suppressed
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[f4c538]
function_test_events_call+0x84/0x188
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[f4c53c]
function_test_events_call+0x88/0x188
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[f4c538]
function_test_events_call+0x84/0x188
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[f4c53c]
function_test_events_call+0x88/0x188
Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[f4c538]
function_test_events_call+0x84/0x188
Dec 14 13:48:15 kernel: OK
Dec 14 13:48:15 kernel: Testing event sched_kthread_stop: OK
...
full log is at https://gist.github.com/mator/a44eb39d5103aaaea2f1b2f3856c391d
Looking at the most encountered function list in dmesg (journalctl -b
-k) output:
$ zgrep 'Kernel unaligned access at TPC' kernel-ftrace.log.gz | awk
'{print $NF}' | cut -f1 -d'+' | sort | uniq -c
313 function_test_events_call
4 trace_event_raw_event_kmem_alloc
4 trace_event_raw_event_kmem_free
1 trace_event_raw_event_mm_page
1 trace_event_raw_event_mm_page_alloc
2 trace_event_raw_event_rcu_utilization
5 trace_event_raw_event_sched_switch
3 trace_event_raw_event_timer_class
2 trace_event_raw_event_timer_expire_entry
8 trace_event_raw_event_workqueue_execute_end
2 trace_event_raw_event_workqueue_execute_start
5 trace_function
Can someone look for unaligned access at least in
function_test_events_call() to fix it?
Thanks.
On Mon, 14 Dec 2020 18:59:02 +0300
Anatoly Pugachev <[email protected]> wrote:
> Hello!
>
> Enabled ftrace startup tests on a sparc64 test VM/LDOM:
>
> $ diff -u <(gzip -dc ~/dmesg/config-5.10.0.gz) <(gzip -dc /proc/config.gz)
> --- /dev/fd/63 2020-12-14 16:19:38.239372599 +0300
> +++ /dev/fd/62 2020-12-14 16:19:38.235372433 +0300
> @@ -2842,7 +2842,10 @@
> # CONFIG_TRACEPOINT_BENCHMARK is not set
> # CONFIG_RING_BUFFER_BENCHMARK is not set
> # CONFIG_TRACE_EVAL_MAP_FILE is not set
> -# CONFIG_FTRACE_STARTUP_TEST is not set
> +CONFIG_FTRACE_SELFTEST=y
> +CONFIG_FTRACE_STARTUP_TEST=y
> +CONFIG_EVENT_TRACE_STARTUP_TEST=y
> +# CONFIG_EVENT_TRACE_TEST_SYSCALLS is not set
> # CONFIG_RING_BUFFER_STARTUP_TEST is not set
> # CONFIG_PREEMPTIRQ_DELAY_TEST is not set
> # CONFIG_KPROBE_EVENT_GEN_TEST is not set
>
>
> Got the following results with kernel boot logs:
>
> Dec 14 13:48:15 kernel: clocksource: jiffies: mask: 0xffffffff
> max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
> Dec 14 13:48:15 kernel: futex hash table entries: 65536 (order: 9,
> 4194304 bytes, linear)
> Dec 14 13:48:15 kernel: Running postponed tracer tests:
> Dec 14 13:48:15 kernel: Testing tracer function:
> Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> trace_function+0x40/0x140
> Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> trace_function+0x44/0x140
> Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> trace_function+0x40/0x140
> Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> trace_function+0x44/0x140
> Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> trace_function+0x40/0x140
Does sparc64 require 8 byte alignment for 8 byte words?
-- Steve
On Mon, Dec 14, 2020 at 11:15:12AM -0500, Steven Rostedt wrote:
> On Mon, 14 Dec 2020 18:59:02 +0300
> Anatoly Pugachev <[email protected]> wrote:
>
> > Hello!
> >
> > Enabled ftrace startup tests on a sparc64 test VM/LDOM:
> >
> > $ diff -u <(gzip -dc ~/dmesg/config-5.10.0.gz) <(gzip -dc /proc/config.gz)
> > --- /dev/fd/63 2020-12-14 16:19:38.239372599 +0300
> > +++ /dev/fd/62 2020-12-14 16:19:38.235372433 +0300
> > @@ -2842,7 +2842,10 @@
> > # CONFIG_TRACEPOINT_BENCHMARK is not set
> > # CONFIG_RING_BUFFER_BENCHMARK is not set
> > # CONFIG_TRACE_EVAL_MAP_FILE is not set
> > -# CONFIG_FTRACE_STARTUP_TEST is not set
> > +CONFIG_FTRACE_SELFTEST=y
> > +CONFIG_FTRACE_STARTUP_TEST=y
> > +CONFIG_EVENT_TRACE_STARTUP_TEST=y
> > +# CONFIG_EVENT_TRACE_TEST_SYSCALLS is not set
> > # CONFIG_RING_BUFFER_STARTUP_TEST is not set
> > # CONFIG_PREEMPTIRQ_DELAY_TEST is not set
> > # CONFIG_KPROBE_EVENT_GEN_TEST is not set
> >
> >
> > Got the following results with kernel boot logs:
> >
> > Dec 14 13:48:15 kernel: clocksource: jiffies: mask: 0xffffffff
> > max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
> > Dec 14 13:48:15 kernel: futex hash table entries: 65536 (order: 9,
> > 4194304 bytes, linear)
> > Dec 14 13:48:15 kernel: Running postponed tracer tests:
> > Dec 14 13:48:15 kernel: Testing tracer function:
> > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > trace_function+0x40/0x140
> > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> > trace_function+0x44/0x140
> > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > trace_function+0x40/0x140
> > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> > trace_function+0x44/0x140
> > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > trace_function+0x40/0x140
>
> Does sparc64 require 8 byte alignment for 8 byte words?
Yes, SPARC requires natural alignment for all primitive types (and that
even includes 8-byte alignment for 8-byte types on 32-bit SPARC as it
has load/store pair instructions the compiler is free to use).
Jess
On Mon, 14 Dec 2020 11:15:12 -0500
Steven Rostedt <[email protected]> wrote:
> Does sparc64 require 8 byte alignment for 8 byte words?
>
In other words, does this patch fix anything?
-- Steve
diff --git a/arch/Kconfig b/arch/Kconfig
index 56b6ccc0e32d..fa716994f77e 100644
--- a/arch/Kconfig
+++ b/arch/Kconfig
@@ -143,6 +143,22 @@ config UPROBES
managed by the kernel and kept transparent to the probed
application. )
+config HAVE_64BIT_ALIGNED_ACCESS
+ def_bool 64BIT && !HAVE_EFFICIENT_UNALIGNED_ACCESS
+ help
+ Some architectures require 64 bit accesses to be 64 bit
+ aligned, which also requires structs containing 64 bit values
+ to be 64 bit aligned too. This includes some 32 bit
+ architectures which can do 64 bit accesses, as well as 64 bit
+ architectures without unaligned access.
+
+ This symbol should be selected by an architecture if 64 bit
+ accesses are required to be 64 bit aligned in this way even
+ though it is not a 64 bit architecture.
+
+ See Documentation/unaligned-memory-access.txt for more
+ information on the topic of unaligned memory accesses.
+
config HAVE_EFFICIENT_UNALIGNED_ACCESS
bool
help
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index f09d3f5911cb..623657f84b72 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -130,7 +130,16 @@ int ring_buffer_print_entry_header(struct trace_seq *s)
#define RB_ALIGNMENT 4U
#define RB_MAX_SMALL_DATA (RB_ALIGNMENT * RINGBUF_TYPE_DATA_TYPE_LEN_MAX)
#define RB_EVNT_MIN_SIZE 8U /* two 32bit words */
-#define RB_ALIGN_DATA __aligned(RB_ALIGNMENT)
+
+#ifndef CONFIG_HAVE_64BIT_ALIGNED_ACCESS
+# define RB_FORCE_8BYTE_ALIGNMENT 0
+# define RB_ARCH_ALIGNMENT RB_ALIGNMENT
+#else
+# define RB_FORCE_8BYTE_ALIGNMENT 1
+# define RB_ARCH_ALIGNMENT 8U
+#endif
+
+#define RB_ALIGN_DATA __aligned(RB_ARCH_ALIGNMENT)
/* define RINGBUF_TYPE_DATA for 'case RINGBUF_TYPE_DATA:' */
#define RINGBUF_TYPE_DATA 0 ... RINGBUF_TYPE_DATA_TYPE_LEN_MAX
@@ -2717,7 +2726,7 @@ rb_update_event(struct ring_buffer_per_cpu *cpu_buffer,
event->time_delta = delta;
length -= RB_EVNT_HDR_SIZE;
- if (length > RB_MAX_SMALL_DATA) {
+ if (length > RB_MAX_SMALL_DATA || RB_FORCE_8BYTE_ALIGNMENT) {
event->type_len = 0;
event->array[0] = length;
} else
@@ -2732,11 +2741,11 @@ static unsigned rb_calculate_event_length(unsigned length)
if (!length)
length++;
- if (length > RB_MAX_SMALL_DATA)
+ if (length > RB_MAX_SMALL_DATA || RB_FORCE_8BYTE_ALIGNMENT)
length += sizeof(event.array[0]);
length += RB_EVNT_HDR_SIZE;
- length = ALIGN(length, RB_ALIGNMENT);
+ length = ALIGN(length, RB_ARCH_ALIGNMENT);
/*
* In case the time delta is larger than the 27 bits for it
On Mon, 14 Dec 2020 16:28:04 +0000
Jessica Clarke <[email protected]> wrote:
> On Mon, Dec 14, 2020 at 11:15:12AM -0500, Steven Rostedt wrote:
> > On Mon, 14 Dec 2020 18:59:02 +0300
> > Anatoly Pugachev <[email protected]> wrote:
> >
> > > Hello!
> > >
> > > Enabled ftrace startup tests on a sparc64 test VM/LDOM:
> > >
> > > $ diff -u <(gzip -dc ~/dmesg/config-5.10.0.gz) <(gzip -dc /proc/config.gz)
> > > --- /dev/fd/63 2020-12-14 16:19:38.239372599 +0300
> > > +++ /dev/fd/62 2020-12-14 16:19:38.235372433 +0300
> > > @@ -2842,7 +2842,10 @@
> > > # CONFIG_TRACEPOINT_BENCHMARK is not set
> > > # CONFIG_RING_BUFFER_BENCHMARK is not set
> > > # CONFIG_TRACE_EVAL_MAP_FILE is not set
> > > -# CONFIG_FTRACE_STARTUP_TEST is not set
> > > +CONFIG_FTRACE_SELFTEST=y
> > > +CONFIG_FTRACE_STARTUP_TEST=y
> > > +CONFIG_EVENT_TRACE_STARTUP_TEST=y
> > > +# CONFIG_EVENT_TRACE_TEST_SYSCALLS is not set
> > > # CONFIG_RING_BUFFER_STARTUP_TEST is not set
> > > # CONFIG_PREEMPTIRQ_DELAY_TEST is not set
> > > # CONFIG_KPROBE_EVENT_GEN_TEST is not set
> > >
> > >
> > > Got the following results with kernel boot logs:
> > >
> > > Dec 14 13:48:15 kernel: clocksource: jiffies: mask: 0xffffffff
> > > max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
> > > Dec 14 13:48:15 kernel: futex hash table entries: 65536 (order: 9,
> > > 4194304 bytes, linear)
> > > Dec 14 13:48:15 kernel: Running postponed tracer tests:
> > > Dec 14 13:48:15 kernel: Testing tracer function:
> > > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > > trace_function+0x40/0x140
> > > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> > > trace_function+0x44/0x140
> > > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > > trace_function+0x40/0x140
> > > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a24]
> > > trace_function+0x44/0x140
> > > Dec 14 13:48:15 kernel: Kernel unaligned access at TPC[552a20]
> > > trace_function+0x40/0x140
> >
> > Does sparc64 require 8 byte alignment for 8 byte words?
>
> Yes, SPARC requires natural alignment for all primitive types (and that
> even includes 8-byte alignment for 8-byte types on 32-bit SPARC as it
> has load/store pair instructions the compiler is free to use).
>
>
OK, that means I was misinformed about reverting the patch that forced
alignment (and the patch I posted in reply to my email, is the revert of
the revert).
If the patch I just posted works, then I'll get it ready for mainline and
stable.
Thanks!
-- Steve
On Mon, Dec 14, 2020 at 7:26 PM Steven Rostedt <[email protected]> wrote:
> On Mon, 14 Dec 2020 11:15:12 -0500 Steven Rostedt <[email protected]> wrote:
>
> > Does sparc64 require 8 byte alignment for 8 byte words?
> >
>
> In other words, does this patch fix anything?
>
> -- Steve
>
> diff --git a/arch/Kconfig b/arch/Kconfig
> index 56b6ccc0e32d..fa716994f77e 100644
> --- a/arch/Kconfig
> +++ b/arch/Kconfig
> @@ -143,6 +143,22 @@ config UPROBES
> managed by the kernel and kept transparent to the probed
> application. )
>
> +config HAVE_64BIT_ALIGNED_ACCESS
...
Steven,
yes, this patch fully fixes ftrace sparc64 "unaligned access". Thanks!
$ journalctl -b -k --no-hostname -o short-monotonic | grep -c unaligned
0
$ diff -u <(gzip -dc ~/dmesg/config-5.10.0.gz) <(gzip -dc /proc/config.gz)
--- /dev/fd/63 2020-12-14 20:11:10.442415669 +0300
+++ /dev/fd/62 2020-12-14 20:11:10.438415619 +0300
@@ -305,6 +305,7 @@
CONFIG_JUMP_LABEL=y
# CONFIG_STATIC_KEYS_SELFTEST is not set
CONFIG_UPROBES=y
+CONFIG_HAVE_64BIT_ALIGNED_ACCESS=y
CONFIG_KRETPROBES=y
CONFIG_HAVE_KPROBES=y
CONFIG_HAVE_KRETPROBES=y
@@ -2842,7 +2843,10 @@
# CONFIG_TRACEPOINT_BENCHMARK is not set
# CONFIG_RING_BUFFER_BENCHMARK is not set
# CONFIG_TRACE_EVAL_MAP_FILE is not set
-# CONFIG_FTRACE_STARTUP_TEST is not set
+CONFIG_FTRACE_SELFTEST=y
+CONFIG_FTRACE_STARTUP_TEST=y
+CONFIG_EVENT_TRACE_STARTUP_TEST=y
+# CONFIG_EVENT_TRACE_TEST_SYSCALLS is not set
# CONFIG_RING_BUFFER_STARTUP_TEST is not set
# CONFIG_PREEMPTIRQ_DELAY_TEST is not set
# CONFIG_KPROBE_EVENT_GEN_TEST is not set