ftrace's __print_symbolic() requires that any enum values used in the
symbol to string translation table be wrapped in a TRACE_DEFINE_ENUM
so that the enum value can be decoded from the ftrace ring buffer by
user space tooling.
This patch also fixes few other problems found in this trace point.
e.g. dereferencing structures in TP_printk which should not be done
at any cost.
Also to avoid checkpatch warnings, this patch removes those
whitespaces/tab stops issues.
Cc: [email protected]
Fixes: commit aa75f4d3daae ("ext4: main fast-commit commit path")
Reported-by: Steven Rostedt <[email protected]>
Signed-off-by: Ritesh Harjani <[email protected]>
Reviewed-by: Jan Kara <[email protected]>
Reviewed-by: Steven Rostedt (Google) <[email protected]>
Reviewed-by: Harshad Shirwadkar <[email protected]>
---
include/trace/events/ext4.h | 78 +++++++++++++++++++++++--------------
1 file changed, 49 insertions(+), 29 deletions(-)
diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 19e957b7f941..1a0b7030f72a 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -95,6 +95,17 @@ TRACE_DEFINE_ENUM(ES_REFERENCED_B);
{ FALLOC_FL_COLLAPSE_RANGE, "COLLAPSE_RANGE"}, \
{ FALLOC_FL_ZERO_RANGE, "ZERO_RANGE"})
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_XATTR);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_CROSS_RENAME);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_NOMEM);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_SWAP_BOOT);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_RESIZE);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_RENAME_DIR);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_FALLOC_RANGE);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_INODE_JOURNAL_DATA);
+TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
+
#define show_fc_reason(reason) \
__print_symbolic(reason, \
{ EXT4_FC_REASON_XATTR, "XATTR"}, \
@@ -2723,41 +2734,50 @@ TRACE_EVENT(ext4_fc_commit_stop,
#define FC_REASON_NAME_STAT(reason) \
show_fc_reason(reason), \
- __entry->sbi->s_fc_stats.fc_ineligible_reason_count[reason]
+ __entry->fc_ineligible_rc[reason]
TRACE_EVENT(ext4_fc_stats,
- TP_PROTO(struct super_block *sb),
-
- TP_ARGS(sb),
+ TP_PROTO(struct super_block *sb),
- TP_STRUCT__entry(
- __field(dev_t, dev)
- __field(struct ext4_sb_info *, sbi)
- __field(int, count)
- ),
+ TP_ARGS(sb),
- TP_fast_assign(
- __entry->dev = sb->s_dev;
- __entry->sbi = EXT4_SB(sb);
- ),
+ TP_STRUCT__entry(
+ __field(dev_t, dev)
+ __array(unsigned int, fc_ineligible_rc, EXT4_FC_REASON_MAX)
+ __field(unsigned long, fc_commits)
+ __field(unsigned long, fc_ineligible_commits)
+ __field(unsigned long, fc_numblks)
+ ),
- TP_printk("dev %d:%d fc ineligible reasons:\n"
- "%s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d; "
- "num_commits:%ld, ineligible: %ld, numblks: %ld",
- MAJOR(__entry->dev), MINOR(__entry->dev),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_XATTR),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_CROSS_RENAME),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_NOMEM),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_SWAP_BOOT),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_RESIZE),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_RENAME_DIR),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_FALLOC_RANGE),
- FC_REASON_NAME_STAT(EXT4_FC_REASON_INODE_JOURNAL_DATA),
- __entry->sbi->s_fc_stats.fc_num_commits,
- __entry->sbi->s_fc_stats.fc_ineligible_commits,
- __entry->sbi->s_fc_stats.fc_numblks)
+ TP_fast_assign(
+ int i;
+ __entry->dev = sb->s_dev;
+ for (i = 0; i < EXT4_FC_REASON_MAX; i++) {
+ __entry->fc_ineligible_rc[i] =
+ EXT4_SB(sb)->s_fc_stats.fc_ineligible_reason_count[i];
+ }
+ __entry->fc_commits = EXT4_SB(sb)->s_fc_stats.fc_num_commits;
+ __entry->fc_ineligible_commits =
+ EXT4_SB(sb)->s_fc_stats.fc_ineligible_commits;
+ __entry->fc_numblks = EXT4_SB(sb)->s_fc_stats.fc_numblks;
+ ),
+
+ TP_printk("dev %d,%d fc ineligible reasons:\n"
+ "%s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u "
+ "num_commits:%lu, ineligible: %lu, numblks: %lu",
+ MAJOR(__entry->dev), MINOR(__entry->dev),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_XATTR),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_CROSS_RENAME),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_NOMEM),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_SWAP_BOOT),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_RESIZE),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_RENAME_DIR),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_FALLOC_RANGE),
+ FC_REASON_NAME_STAT(EXT4_FC_REASON_INODE_JOURNAL_DATA),
+ __entry->fc_commits, __entry->fc_ineligible_commits,
+ __entry->fc_numblks)
);
#define DEFINE_TRACE_DENTRY_EVENT(__type) \
--
2.31.1
On Sat, 12 Mar 2022 11:09:47 +0530
Ritesh Harjani <[email protected]> wrote:
> ftrace's __print_symbolic() requires that any enum values used in the
> symbol to string translation table be wrapped in a TRACE_DEFINE_ENUM
> so that the enum value can be decoded from the ftrace ring buffer by
> user space tooling.
>
> This patch also fixes few other problems found in this trace point.
> e.g. dereferencing structures in TP_printk which should not be done
> at any cost.
>
> Also to avoid checkpatch warnings, this patch removes those
> whitespaces/tab stops issues.
>
It is recommend now that when there's a fixes and a reported-by tag,
you should include the link to the report when available.
Link: https://lore.kernel.org/all/[email protected]/
-- Steve
> Cc: [email protected]
> Fixes: commit aa75f4d3daae ("ext4: main fast-commit commit path")
> Reported-by: Steven Rostedt <[email protected]>
> Signed-off-by: Ritesh Harjani <[email protected]>
> Reviewed-by: Jan Kara <[email protected]>
> Reviewed-by: Steven Rostedt (Google) <[email protected]>
> Reviewed-by: Harshad Shirwadkar <[email protected]>
> ---
> include/trace/events/ext4.h | 78 +++++++++++++++++++++++--------------
> 1 file changed, 49 insertions(+), 29 deletions(-)
>
> diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> index 19e957b7f941..1a0b7030f72a 100644
> --- a/include/trace/events/ext4.h
> +++ b/include/trace/events/ext4.h
> @@ -95,6 +95,17 @@ TRACE_DEFINE_ENUM(ES_REFERENCED_B);
> { FALLOC_FL_COLLAPSE_RANGE, "COLLAPSE_RANGE"}, \
> { FALLOC_FL_ZERO_RANGE, "ZERO_RANGE"})
>
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_XATTR);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_CROSS_RENAME);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_NOMEM);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_SWAP_BOOT);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RESIZE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RENAME_DIR);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_FALLOC_RANGE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_INODE_JOURNAL_DATA);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
> +
> #define show_fc_reason(reason) \
> __print_symbolic(reason, \
> { EXT4_FC_REASON_XATTR, "XATTR"}, \
> @@ -2723,41 +2734,50 @@ TRACE_EVENT(ext4_fc_commit_stop,
>
> #define FC_REASON_NAME_STAT(reason) \
> show_fc_reason(reason), \
> - __entry->sbi->s_fc_stats.fc_ineligible_reason_count[reason]
> + __entry->fc_ineligible_rc[reason]
>
> TRACE_EVENT(ext4_fc_stats,
> - TP_PROTO(struct super_block *sb),
> -
> - TP_ARGS(sb),
> + TP_PROTO(struct super_block *sb),
>
> - TP_STRUCT__entry(
> - __field(dev_t, dev)
> - __field(struct ext4_sb_info *, sbi)
> - __field(int, count)
> - ),
> + TP_ARGS(sb),
>
> - TP_fast_assign(
> - __entry->dev = sb->s_dev;
> - __entry->sbi = EXT4_SB(sb);
> - ),
> + TP_STRUCT__entry(
> + __field(dev_t, dev)
> + __array(unsigned int, fc_ineligible_rc, EXT4_FC_REASON_MAX)
> + __field(unsigned long, fc_commits)
> + __field(unsigned long, fc_ineligible_commits)
> + __field(unsigned long, fc_numblks)
> + ),
>
> - TP_printk("dev %d:%d fc ineligible reasons:\n"
> - "%s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d, %s:%d; "
> - "num_commits:%ld, ineligible: %ld, numblks: %ld",
> - MAJOR(__entry->dev), MINOR(__entry->dev),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_XATTR),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_CROSS_RENAME),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_NOMEM),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_SWAP_BOOT),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_RESIZE),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_RENAME_DIR),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_FALLOC_RANGE),
> - FC_REASON_NAME_STAT(EXT4_FC_REASON_INODE_JOURNAL_DATA),
> - __entry->sbi->s_fc_stats.fc_num_commits,
> - __entry->sbi->s_fc_stats.fc_ineligible_commits,
> - __entry->sbi->s_fc_stats.fc_numblks)
> + TP_fast_assign(
> + int i;
>
> + __entry->dev = sb->s_dev;
> + for (i = 0; i < EXT4_FC_REASON_MAX; i++) {
> + __entry->fc_ineligible_rc[i] =
> + EXT4_SB(sb)->s_fc_stats.fc_ineligible_reason_count[i];
> + }
> + __entry->fc_commits = EXT4_SB(sb)->s_fc_stats.fc_num_commits;
> + __entry->fc_ineligible_commits =
> + EXT4_SB(sb)->s_fc_stats.fc_ineligible_commits;
> + __entry->fc_numblks = EXT4_SB(sb)->s_fc_stats.fc_numblks;
> + ),
> +
> + TP_printk("dev %d,%d fc ineligible reasons:\n"
> + "%s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u, %s:%u "
> + "num_commits:%lu, ineligible: %lu, numblks: %lu",
> + MAJOR(__entry->dev), MINOR(__entry->dev),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_XATTR),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_CROSS_RENAME),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_NOMEM),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_SWAP_BOOT),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_RESIZE),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_RENAME_DIR),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_FALLOC_RANGE),
> + FC_REASON_NAME_STAT(EXT4_FC_REASON_INODE_JOURNAL_DATA),
> + __entry->fc_commits, __entry->fc_ineligible_commits,
> + __entry->fc_numblks)
> );
>
> #define DEFINE_TRACE_DENTRY_EVENT(__type) \
Ritesh Harjani <[email protected]> writes:
> ftrace's __print_symbolic() requires that any enum values used in the
> symbol to string translation table be wrapped in a TRACE_DEFINE_ENUM
> so that the enum value can be decoded from the ftrace ring buffer by
> user space tooling.
>
> This patch also fixes few other problems found in this trace point.
> e.g. dereferencing structures in TP_printk which should not be done
> at any cost.
>
> Also to avoid checkpatch warnings, this patch removes those
> whitespaces/tab stops issues.
>
> Cc: [email protected]
> Fixes: commit aa75f4d3daae ("ext4: main fast-commit commit path")
> Reported-by: Steven Rostedt <[email protected]>
> Signed-off-by: Ritesh Harjani <[email protected]>
> Reviewed-by: Jan Kara <[email protected]>
> Reviewed-by: Steven Rostedt (Google) <[email protected]>
> Reviewed-by: Harshad Shirwadkar <[email protected]>
> ---
> include/trace/events/ext4.h | 78 +++++++++++++++++++++++--------------
> 1 file changed, 49 insertions(+), 29 deletions(-)
>
> diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> index 19e957b7f941..1a0b7030f72a 100644
> --- a/include/trace/events/ext4.h
> +++ b/include/trace/events/ext4.h
> @@ -95,6 +95,17 @@ TRACE_DEFINE_ENUM(ES_REFERENCED_B);
> { FALLOC_FL_COLLAPSE_RANGE, "COLLAPSE_RANGE"}, \
> { FALLOC_FL_ZERO_RANGE, "ZERO_RANGE"})
>
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_XATTR);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_CROSS_RENAME);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_NOMEM);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_SWAP_BOOT);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RESIZE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RENAME_DIR);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_FALLOC_RANGE);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_INODE_JOURNAL_DATA);
> +TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
I'm getting the following oops with that patch:
[ 0.937455] VFS: Disk quotas dquot_6.6.0
[ 0.937474] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.958347] Unable to handle kernel pointer dereference in virtual kernel address space
[ 0.958350] Failing address: 00000000010de000 TEID: 00000000010de407
[ 0.958353] Fault in home space mode while using kernel ASCE.
[ 0.958357] AS:0000000001ed0007 R3:00000002ffff0007 S:0000000001003701
[ 0.958388] Oops: 0004 ilc:3 [#1] SMP
[ 0.958393] Modules linked in:
[ 0.958398] CPU: 0 PID: 8 Comm: kworker/u128:0 Not tainted 5.17.0-rc8-next-20220317 #396
[ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
[ 0.958407] Workqueue: eval_map_wq eval_map_work_func
[ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
[ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
[ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
[ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
[ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
[ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
[ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
[ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
[ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
[ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
[ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
[ 0.958494] 000000000090a9e0: a74bffff
aghi %r4,-1
[ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
[ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
[ 0.958575] Call Trace:
[ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
[ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
[ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
[ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
[ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
[ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
[ 0.958619] [<0000000000171bba>] process_one_work+0x1fa/0x460
[ 0.958625] [<000000000017234c>] worker_thread+0x64/0x468
[ 0.958629] [<000000000017af90>] kthread+0x108/0x110
[ 0.958634] [<00000000001032ec>] __ret_from_fork+0x3c/0x58
[ 0.958640] [<0000000000cce43a>] ret_from_fork+0xa/0x40
[ 0.958648] Last Breaking-Event-Address:
[ 0.958652] [<000000000090a99c>] number+0x224/0x3c0
[ 0.958661] Kernel panic - not syncing: Fatal exception: panic_on_oops
I haven't really checked what TRACE_DEFINE_ENUM() does, but removing the
last line ("TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);") makes the oops go
away. Looking at all the other defines looks like the _MAX enum
shouldn't be added there?
Thanks
Sven
Hi,
Ritesh Harjani <[email protected]> writes:
> On 22/03/17 01:01PM, Sven Schnelle wrote:
>> Ritesh Harjani <[email protected]> writes:
>> I'm getting the following oops with that patch:
>>
>> [ 0.937455] VFS: Disk quotas dquot_6.6.0
>> [ 0.937474] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
>> [ 0.958347] Unable to handle kernel pointer dereference in virtual kernel address space
>> [ 0.958350] Failing address: 00000000010de000 TEID: 00000000010de407
>> [ 0.958353] Fault in home space mode while using kernel ASCE.
>> [ 0.958357] AS:0000000001ed0007 R3:00000002ffff0007 S:0000000001003701
>> [ 0.958388] Oops: 0004 ilc:3 [#1] SMP
>> [ 0.958393] Modules linked in:
>> [ 0.958398] CPU: 0 PID: 8 Comm: kworker/u128:0 Not tainted 5.17.0-rc8-next-20220317 #396
>
> I tried running this master branch of linux-next from here [1].
> But I started facing build failures with it.
>
> [1]: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
>
>> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
>> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
>>
>> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
>> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
>> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
>> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
>> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
>> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
>> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
>> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
>> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
>> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
>> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
>> [ 0.958494] 000000000090a9e0: a74bffff
>> aghi %r4,-1
>> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
>> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
>> [ 0.958575] Call Trace:
>> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
>> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
>> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
>> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
>> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
>> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
>
> This looks like you must have this patch from Steven as well [2].
Yes, i used vanilla linux-next from 20220317. So i have that one as well.
Looking at that patch it looks like TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
is indeed wanted. Lets wait wether Steve knows what's going on,
otherwise i have to dig into the code and figure out what the problem is.
Thanks
Sven
On 22/03/17 01:01PM, Sven Schnelle wrote:
> Ritesh Harjani <[email protected]> writes:
>
> > ftrace's __print_symbolic() requires that any enum values used in the
> > symbol to string translation table be wrapped in a TRACE_DEFINE_ENUM
> > so that the enum value can be decoded from the ftrace ring buffer by
> > user space tooling.
> >
> > This patch also fixes few other problems found in this trace point.
> > e.g. dereferencing structures in TP_printk which should not be done
> > at any cost.
> >
> > Also to avoid checkpatch warnings, this patch removes those
> > whitespaces/tab stops issues.
> >
> > Cc: [email protected]
> > Fixes: commit aa75f4d3daae ("ext4: main fast-commit commit path")
> > Reported-by: Steven Rostedt <[email protected]>
> > Signed-off-by: Ritesh Harjani <[email protected]>
> > Reviewed-by: Jan Kara <[email protected]>
> > Reviewed-by: Steven Rostedt (Google) <[email protected]>
> > Reviewed-by: Harshad Shirwadkar <[email protected]>
> > ---
> > include/trace/events/ext4.h | 78 +++++++++++++++++++++++--------------
> > 1 file changed, 49 insertions(+), 29 deletions(-)
> >
> > diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> > index 19e957b7f941..1a0b7030f72a 100644
> > --- a/include/trace/events/ext4.h
> > +++ b/include/trace/events/ext4.h
> > @@ -95,6 +95,17 @@ TRACE_DEFINE_ENUM(ES_REFERENCED_B);
> > { FALLOC_FL_COLLAPSE_RANGE, "COLLAPSE_RANGE"}, \
> > { FALLOC_FL_ZERO_RANGE, "ZERO_RANGE"})
> >
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_XATTR);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_CROSS_RENAME);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_JOURNAL_FLAG_CHANGE);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_NOMEM);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_SWAP_BOOT);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RESIZE);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_RENAME_DIR);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_FALLOC_RANGE);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_INODE_JOURNAL_DATA);
> > +TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
>
> I'm getting the following oops with that patch:
>
> [ 0.937455] VFS: Disk quotas dquot_6.6.0
> [ 0.937474] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
> [ 0.958347] Unable to handle kernel pointer dereference in virtual kernel address space
> [ 0.958350] Failing address: 00000000010de000 TEID: 00000000010de407
> [ 0.958353] Fault in home space mode while using kernel ASCE.
> [ 0.958357] AS:0000000001ed0007 R3:00000002ffff0007 S:0000000001003701
> [ 0.958388] Oops: 0004 ilc:3 [#1] SMP
> [ 0.958393] Modules linked in:
> [ 0.958398] CPU: 0 PID: 8 Comm: kworker/u128:0 Not tainted 5.17.0-rc8-next-20220317 #396
I tried running this master branch of linux-next from here [1].
But I started facing build failures with it.
[1]: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
>
> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
> [ 0.958494] 000000000090a9e0: a74bffff
> aghi %r4,-1
> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
> [ 0.958575] Call Trace:
> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
This looks like you must have this patch from Steven as well [2].
Although I did test the patch and didn't see such a crash on my qemu box [3].
[2]: https://lore.kernel.org/linux-ext4/[email protected]/
[3]: https://lore.kernel.org/linux-ext4/20220311051249.ltgqbjjothbrkbno@riteshh-domain/
@Steven,
Sorry to bother. But does this crash strike anything obvious to you?
-ritesh
> [ 0.958619] [<0000000000171bba>] process_one_work+0x1fa/0x460
> [ 0.958625] [<000000000017234c>] worker_thread+0x64/0x468
> [ 0.958629] [<000000000017af90>] kthread+0x108/0x110
> [ 0.958634] [<00000000001032ec>] __ret_from_fork+0x3c/0x58
> [ 0.958640] [<0000000000cce43a>] ret_from_fork+0xa/0x40
> [ 0.958648] Last Breaking-Event-Address:
> [ 0.958652] [<000000000090a99c>] number+0x224/0x3c0
> [ 0.958661] Kernel panic - not syncing: Fatal exception: panic_on_oops
>
> I haven't really checked what TRACE_DEFINE_ENUM() does, but removing the
> last line ("TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);") makes the oops go
> away. Looking at all the other defines looks like the _MAX enum
> shouldn't be added there?
>
> Thanks
> Sven
On Thu, Mar 17, 2022 at 05:11:42PM +0100, Sven Schnelle wrote:
> Hi,
>
> Ritesh Harjani <[email protected]> writes:
>
> > On 22/03/17 01:01PM, Sven Schnelle wrote:
> >> Ritesh Harjani <[email protected]> writes:
> >>
> >> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
> >> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
> >>
> >> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
> >> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> >> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
> >> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
> >> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
> >> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
> >> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
> >> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
> >> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
> >> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
> >> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
> >> [ 0.958494] 000000000090a9e0: a74bffff
> >> aghi %r4,-1
> >> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
> >> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
> >> [ 0.958575] Call Trace:
> >> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
> >> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
> >> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
> >> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
> >> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
> >> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
> >
> > This looks like you must have this patch from Steven as well [2].
> > Although I did test the patch and didn't see such a crash on my qemu box [3].
Indeed, commit b3bc8547d3be ("tracing: Have TRACE_DEFINE_ENUM affect
trace event types as well") from the ftrace tree is required to
reproduce this. The ftrace and ext4 changes alone are fine (my initial
bisect landed on a merge and I did two more bisects to confirm that).
> > [2]: https://lore.kernel.org/linux-ext4/[email protected]/
> > [3]: https://lore.kernel.org/linux-ext4/20220311051249.ltgqbjjothbrkbno@riteshh-domain/
> >
> > @Steven,
> > Sorry to bother. But does this crash strike anything obvious to you?
>
> Looking at the oops output again made me realizes that the snprintf
> tries to write into pages that are mapped RO. Talking to Heiko he
> mentioned that s390 maps rodata/text RO when setting up the initial
> mapping while x86 has a RW mapping in the beginning and changes that
> later to RO. I haven't verified that, but that might be a reason why it
> works on x86.
For what it's worth, this is reproducible on all of my x86 boxes during
the initial boot on next-20220316 and newer. I am happy to test any
patches or provide further information as necessary.
Cheers,
Nathan
You already replied, but this was what I was working on.
On Thu, 17 Mar 2022 13:01:49 +0100
Sven Schnelle <[email protected]> wrote:
> I'm getting the following oops with that patch:
I think I know the issue.
>
> [ 0.937455] VFS: Disk quotas dquot_6.6.0
> [ 0.937474] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
> [ 0.958347] Unable to handle kernel pointer dereference in virtual kernel address space
> [ 0.958350] Failing address: 00000000010de000 TEID: 00000000010de407
> [ 0.958353] Fault in home space mode while using kernel ASCE.
> [ 0.958357] AS:0000000001ed0007 R3:00000002ffff0007 S:0000000001003701
> [ 0.958388] Oops: 0004 ilc:3 [#1] SMP
> [ 0.958393] Modules linked in:
> [ 0.958398] CPU: 0 PID: 8 Comm: kworker/u128:0 Not tainted 5.17.0-rc8-next-20220317 #396
> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
I'm guessing this is a s390?
> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
>
> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
> [ 0.958494] 000000000090a9e0: a74bffff
> aghi %r4,-1
> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
> [ 0.958575] Call Trace:
> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
> [ 0.958619] [<0000000000171bba>] process_one_work+0x1fa/0x460
> [ 0.958625] [<000000000017234c>] worker_thread+0x64/0x468
> [ 0.958629] [<000000000017af90>] kthread+0x108/0x110
> [ 0.958634] [<00000000001032ec>] __ret_from_fork+0x3c/0x58
> [ 0.958640] [<0000000000cce43a>] ret_from_fork+0xa/0x40
> [ 0.958648] Last Breaking-Event-Address:
> [ 0.958652] [<000000000090a99c>] number+0x224/0x3c0
> [ 0.958661] Kernel panic - not syncing: Fatal exception: panic_on_oops
>
> I haven't really checked what TRACE_DEFINE_ENUM() does, but removing the
> last line ("TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);") makes the oops go
> away. Looking at all the other defines looks like the _MAX enum
> shouldn't be added there?
What I believe is happening is that we are modifying different memory to
fix up the enums by the types. The print_fmt happens to be defined by:
static char print_fmt_##call[] = print;
Which is writable. But the types are defined with:
.type = #_type"["__stringify(_len)"]", .name = #_item,
Which are not. It just so happens that on x86 this is still writable
during boot up, so it wasn't a problem.
[ here I wanted to add a patch, but I haven't figured out the best way to
fix it yet. ]
-- Steve
On Thu, 17 Mar 2022 16:22:08 +0100
Sven Schnelle <[email protected]> wrote:
> > This looks like you must have this patch from Steven as well [2].
>
> Yes, i used vanilla linux-next from 20220317. So i have that one as well.
> Looking at that patch it looks like TRACE_DEFINE_ENUM(EXT4_FC_REASON_MAX);
> is indeed wanted. Lets wait wether Steve knows what's going on,
> otherwise i have to dig into the code and figure out what the problem is.
I just downloaded the latest next, and will see if I can trigger it.
Thanks,
-- Steve
On 22/03/17 10:43AM, Nathan Chancellor wrote:
> On Thu, Mar 17, 2022 at 05:11:42PM +0100, Sven Schnelle wrote:
> > Hi,
> >
> > Ritesh Harjani <[email protected]> writes:
> >
> > > On 22/03/17 01:01PM, Sven Schnelle wrote:
> > >> Ritesh Harjani <[email protected]> writes:
> > >>
> > >> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
> > >> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
> > >>
> > >> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
> > >> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> > >> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
> > >> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
> > >> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
> > >> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
> > >> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
> > >> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
> > >> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
> > >> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
> > >> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
> > >> [ 0.958494] 000000000090a9e0: a74bffff
> > >> aghi %r4,-1
> > >> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
> > >> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
> > >> [ 0.958575] Call Trace:
> > >> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
> > >> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
> > >> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
> > >> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
> > >> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
> > >> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
> > >
> > > This looks like you must have this patch from Steven as well [2].
> > > Although I did test the patch and didn't see such a crash on my qemu box [3].
>
> Indeed, commit b3bc8547d3be ("tracing: Have TRACE_DEFINE_ENUM affect
> trace event types as well") from the ftrace tree is required to
> reproduce this. The ftrace and ext4 changes alone are fine (my initial
> bisect landed on a merge and I did two more bisects to confirm that).
>
> > > [2]: https://lore.kernel.org/linux-ext4/[email protected]/
> > > [3]: https://lore.kernel.org/linux-ext4/20220311051249.ltgqbjjothbrkbno@riteshh-domain/
> > >
> > > @Steven,
> > > Sorry to bother. But does this crash strike anything obvious to you?
> >
> > Looking at the oops output again made me realizes that the snprintf
> > tries to write into pages that are mapped RO. Talking to Heiko he
> > mentioned that s390 maps rodata/text RO when setting up the initial
> > mapping while x86 has a RW mapping in the beginning and changes that
> > later to RO. I haven't verified that, but that might be a reason why it
> > works on x86.
>
> For what it's worth, this is reproducible on all of my x86 boxes during
> the initial boot on next-20220316 and newer. I am happy to test any
> patches or provide further information as necessary.
Thanks for reporting.
Could you please share your kernel config with which you are seeing this to be
reproducible on x86?
-ritesh
>
> Cheers,
> Nathan
Hi Ritesh,
On Fri, Mar 18, 2022 at 09:44:53AM +0530, Ritesh Harjani wrote:
> On 22/03/17 10:43AM, Nathan Chancellor wrote:
> > On Thu, Mar 17, 2022 at 05:11:42PM +0100, Sven Schnelle wrote:
> > > Hi,
> > >
> > > Ritesh Harjani <[email protected]> writes:
> > >
> > > > On 22/03/17 01:01PM, Sven Schnelle wrote:
> > > >> Ritesh Harjani <[email protected]> writes:
> > > >>
> > > >> [ 0.958403] Hardware name: IBM 3906 M04 704 (z/VM 7.1.0)
> > > >> [ 0.958407] Workqueue: eval_map_wq eval_map_work_func
> > > >>
> > > >> [ 0.958446] Krnl PSW : 0704e00180000000 000000000090a9d6 (number+0x25e/0x3c0)
> > > >> [ 0.958456] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> > > >> [ 0.958461] Krnl GPRS: 0000000000000058 00000000010de0ac 0000000000000001 00000000fffffffc
> > > >> [ 0.958467] 0000038000047b80 0affffff010de0ab 0000000000000000 0000000000000000
> > > >> [ 0.958481] 0000000000000020 0000038000000000 00000000010de0ad 00000000010de0ab
> > > >> [ 0.958484] 0000000080312100 0000000000e68910 0000038000047b50 0000038000047ab8
> > > >> [ 0.958494] Krnl Code: 000000000090a9c6: f0c84112b001 srp 274(13,%r4),1(%r11),8
> > > >> [ 0.958494] 000000000090a9cc: 41202001 la %r2,1(%r2)
> > > >> [ 0.958494] #000000000090a9d0: ecab0006c065 clgrj %r10,%r11,12,000000000090a9dc
> > > >> [ 0.958494] >000000000090a9d6: d200b0004000 mvc 0(1,%r11),0(%r4)
> > > >> [ 0.958494] 000000000090a9dc: 41b0b001 la %r11,1(%r11)
> > > >> [ 0.958494] 000000000090a9e0: a74bffff
> > > >> aghi %r4,-1
> > > >> [ 0.958494] 000000000090a9e4: a727fff6 brctg %r2,000000000090a9d0
> > > >> [ 0.958494] 000000000090a9e8: a73affff ahi %r3,-1
> > > >> [ 0.958575] Call Trace:
> > > >> [ 0.958580] [<000000000090a9d6>] number+0x25e/0x3c0
> > > >> [ 0.958594] ([<0000000000289516>] update_event_printk+0xde/0x200)
> > > >> [ 0.958602] [<0000000000910020>] vsnprintf+0x4b0/0x7c8
> > > >> [ 0.958606] [<00000000009103e8>] snprintf+0x40/0x50
> > > >> [ 0.958610] [<00000000002893d2>] eval_replace+0x62/0xc8
> > > >> [ 0.958614] [<000000000028e2fe>] trace_event_eval_update+0x206/0x248
> > > >
> > > > This looks like you must have this patch from Steven as well [2].
> > > > Although I did test the patch and didn't see such a crash on my qemu box [3].
> >
> > Indeed, commit b3bc8547d3be ("tracing: Have TRACE_DEFINE_ENUM affect
> > trace event types as well") from the ftrace tree is required to
> > reproduce this. The ftrace and ext4 changes alone are fine (my initial
> > bisect landed on a merge and I did two more bisects to confirm that).
> >
> > > > [2]: https://lore.kernel.org/linux-ext4/[email protected]/
> > > > [3]: https://lore.kernel.org/linux-ext4/20220311051249.ltgqbjjothbrkbno@riteshh-domain/
> > > >
> > > > @Steven,
> > > > Sorry to bother. But does this crash strike anything obvious to you?
> > >
> > > Looking at the oops output again made me realizes that the snprintf
> > > tries to write into pages that are mapped RO. Talking to Heiko he
> > > mentioned that s390 maps rodata/text RO when setting up the initial
> > > mapping while x86 has a RW mapping in the beginning and changes that
> > > later to RO. I haven't verified that, but that might be a reason why it
> > > works on x86.
> >
> > For what it's worth, this is reproducible on all of my x86 boxes during
> > the initial boot on next-20220316 and newer. I am happy to test any
> > patches or provide further information as necessary.
>
> Thanks for reporting.
>
> Could you please share your kernel config with which you are seeing this to be
> reproducible on x86?
Sure thing, it is just Arch Linux's config:
https://github.com/archlinux/svntogit-packages/raw/packages/linux/trunk/config
I have attached my version as well, just in case there are any subtle
differences.
Cheers,
Nathan
On Thu, 17 Mar 2022 14:39:38 -0400
Steven Rostedt <[email protected]> wrote:
> [ here I wanted to add a patch, but I haven't figured out the best way to
> fix it yet. ]
Care to try this patch?
-- Steve
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index 7b558c72f595..e11e167b7809 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -40,6 +40,14 @@ static LIST_HEAD(ftrace_generic_fields);
static LIST_HEAD(ftrace_common_fields);
static bool eventdir_initialized;
+static LIST_HEAD(module_strings);
+
+struct module_string {
+ struct list_head next;
+ struct module *module;
+ char *str;
+};
+
#define GFP_TRACE (GFP_KERNEL | __GFP_ZERO)
static struct kmem_cache *field_cachep;
@@ -2643,14 +2651,40 @@ static void update_event_printk(struct trace_event_call *call,
}
}
+static void add_str_to_module(struct module *module, char *str)
+{
+ struct module_string *modstr;
+
+ modstr = kmalloc(sizeof(*modstr), GFP_KERNEL);
+
+ /*
+ * If we failed to allocate memory here, then we'll just
+ * let the str memory leak when the module is removed.
+ * If this fails to allocate, there's worse problems than
+ * a leaked string on module removal.
+ */
+ if (WARN_ON_ONCE(!modstr))
+ return;
+
+ modstr->module = module;
+ modstr->str = str;
+
+ list_add(&modstr->next, &module_strings);
+}
+
static void update_event_fields(struct trace_event_call *call,
struct trace_eval_map *map)
{
struct ftrace_event_field *field;
struct list_head *head;
char *ptr;
+ char *str;
int len = strlen(map->eval_string);
+ /* Dynamic events should never have field maps */
+ if (WARN_ON_ONCE(call->flags & TRACE_EVENT_FL_DYNAMIC))
+ return;
+
head = trace_get_fields(call);
list_for_each_entry(field, head, link) {
ptr = strchr(field->type, '[');
@@ -2664,9 +2698,26 @@ static void update_event_fields(struct trace_event_call *call,
if (strncmp(map->eval_string, ptr, len) != 0)
continue;
+ str = kstrdup(field->type, GFP_KERNEL);
+ if (WARN_ON_ONCE(!str))
+ return;
+ ptr = str + (ptr - field->type);
ptr = eval_replace(ptr, map, len);
/* enum/sizeof string smaller than value */
- WARN_ON_ONCE(!ptr);
+ if (WARN_ON_ONCE(!ptr)) {
+ kfree(str);
+ continue;
+ }
+
+ /*
+ * If the event is part of a module, then we need to free the string
+ * when the module is removed. Otherwise, it will stay allocated
+ * until a reboot.
+ */
+ if (call->module)
+ add_str_to_module(call->module, str);
+
+ field->type = str;
}
}
@@ -2893,6 +2944,7 @@ static void trace_module_add_events(struct module *mod)
static void trace_module_remove_events(struct module *mod)
{
struct trace_event_call *call, *p;
+ struct module_string *modstr, *m;
down_write(&trace_event_sem);
list_for_each_entry_safe(call, p, &ftrace_events, list) {
@@ -2901,6 +2953,14 @@ static void trace_module_remove_events(struct module *mod)
if (call->module == mod)
__trace_remove_event_call(call);
}
+ /* Check for any strings allocade for this module */
+ list_for_each_entry_safe(modstr, m, &module_strings, next) {
+ if (modstr->module != mod)
+ continue;
+ list_del(&modstr->next);
+ kfree(modstr->str);
+ kfree(modstr);
+ }
up_write(&trace_event_sem);
/*
On 22/03/18 12:30PM, Steven Rostedt wrote:
> On Thu, 17 Mar 2022 14:39:38 -0400
> Steven Rostedt <[email protected]> wrote:
>
> > [ here I wanted to add a patch, but I haven't figured out the best way to
> > fix it yet. ]
>
> Care to try this patch?
>
fwiw, I gave this patch a try (on x86 and ppc64le guests) and with it
ext4_fc_stats() trace event is working fine as expected. Although I could
never reproduced the original issue which Sven reported on his s390x box.
So will wait till Sven also give this a try.
Thanks!!
-ritesh