From 64805e4039f1687b9857034123a9ec10bb9abddd Mon Sep 17 00:00:00 2001 From: Beau Belgrave Date: Thu, 22 Feb 2024 00:18:05 +0000 Subject: tracing/user_events: Introduce multi-format events Currently user_events supports 1 event with the same name and must have the exact same format when referenced by multiple programs. This opens an opportunity for malicious or poorly thought through programs to create events that others use with different formats. Another scenario is user programs wishing to use the same event name but add more fields later when the software updates. Various versions of a program may be running side-by-side, which is prevented by the current single format requirement. Add a new register flag (USER_EVENT_REG_MULTI_FORMAT) which indicates the user program wishes to use the same user_event name, but may have several different formats of the event. When this flag is used, create the underlying tracepoint backing the user_event with a unique name per-version of the format. It's important that existing ABI users do not get this logic automatically, even if one of the multi format events matches the format. This ensures existing programs that create events and assume the tracepoint name will match exactly continue to work as expected. Add logic to only check multi-format events with other multi-format events and single-format events to only check single-format events during find. Change system name of the multi-format event tracepoint to ensure that multi-format events are isolated completely from single-format events. This prevents single-format names from conflicting with multi-format events if they end with the same suffix as the multi-format events. Add a register_name (reg_name) to the user_event struct which allows for split naming of events. We now have the name that was used to register within user_events as well as the unique name for the tracepoint. Upon registering events ensure matches based on first the reg_name, followed by the fields and format of the event. This allows for multiple events with the same registered name to have different formats. The underlying tracepoint will have a unique name in the format of {reg_name}.{unique_id}. For example, if both "test u32 value" and "test u64 value" are used with the USER_EVENT_REG_MULTI_FORMAT the system would have 2 unique tracepoints. The dynamic_events file would then show the following: u:test u64 count u:test u32 count The actual tracepoint names look like this: test.0 test.1 Both would be under the new user_events_multi system name to prevent the older ABI from being used to squat on multi-formatted events and block their use. Deleting events via "!u:test u64 count" would only delete the first tracepoint that matched that format. When the delete ABI is used all events with the same name will be attempted to be deleted. If per-version deletion is required, user programs should either not use persistent events or delete them via dynamic_events. Link: https://lore.kernel.org/linux-trace-kernel/20240222001807.1463-3-beaub@linux.microsoft.com Signed-off-by: Beau Belgrave Signed-off-by: Steven Rostedt (Google) --- include/uapi/linux/user_events.h | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) (limited to 'include') diff --git a/include/uapi/linux/user_events.h b/include/uapi/linux/user_events.h index f74f3aedd49c..a03de03dccbc 100644 --- a/include/uapi/linux/user_events.h +++ b/include/uapi/linux/user_events.h @@ -12,6 +12,7 @@ #include #define USER_EVENTS_SYSTEM "user_events" +#define USER_EVENTS_MULTI_SYSTEM "user_events_multi" #define USER_EVENTS_PREFIX "u:" /* Create dynamic location entry within a 32-bit value */ @@ -22,8 +23,11 @@ enum user_reg_flag { /* Event will not delete upon last reference closing */ USER_EVENT_REG_PERSIST = 1U << 0, + /* Event will be allowed to have multiple formats */ + USER_EVENT_REG_MULTI_FORMAT = 1U << 1, + /* This value or above is currently non-ABI */ - USER_EVENT_REG_MAX = 1U << 1, + USER_EVENT_REG_MAX = 1U << 2, }; /* -- cgit v1.2.3 From c1fa617caeb005e7e3db60826cff6dddebb0363f Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Thu, 22 Feb 2024 16:14:16 -0500 Subject: tracing: Rework __assign_str() and __string() to not duplicate getting the string MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The TRACE_EVENT() macro handles dynamic strings by having: TP_PROTO(struct some_struct *s), TP_ARGS(s), TP_STRUCT__entry( __string(my_string, s->string) ), TP_fast_assign( __assign_str(my_string, s->string); ) TP_printk("%s", __get_str(my_string)) There's even some code that may call a function helper to find the s->string value. The problem with the above is that the work to get the s->string is done twice. Once at the __string() and again in the __assign_str(). But the __string() uses dynamic_array() which has a helper structure that is created holding the offsets and length of the string fields. Instead of finding the string twice, just save it off in another field from that helper structure, and have __assign_str() use that instead. Note, this also means that the second parameter of __assign_str() isn't even used anymore, and may be removed in the future. Link: https://lore.kernel.org/linux-trace-kernel/20240222211442.634192653@goodmis.org Cc: Masami Hiramatsu Cc: Mark Rutland Cc: Mathieu Desnoyers Cc: Andrew Morton Cc: Ville Syrjälä Cc: Rodrigo Vivi Cc: Chuck Lever Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage2_data_offsets.h | 4 ++-- include/trace/stages/stage5_get_offsets.h | 15 ++++++++++----- include/trace/stages/stage6_event_callback.h | 12 ++++++++---- 3 files changed, 20 insertions(+), 11 deletions(-) (limited to 'include') diff --git a/include/trace/stages/stage2_data_offsets.h b/include/trace/stages/stage2_data_offsets.h index 469b6a64293d..8b0cff06d346 100644 --- a/include/trace/stages/stage2_data_offsets.h +++ b/include/trace/stages/stage2_data_offsets.h @@ -24,7 +24,7 @@ #define __array(type, item, len) #undef __dynamic_array -#define __dynamic_array(type, item, len) u32 item; +#define __dynamic_array(type, item, len) u32 item; const void *item##_ptr_; #undef __string #define __string(item, src) __dynamic_array(char, item, -1) @@ -45,7 +45,7 @@ #define __sockaddr(field, len) __dynamic_array(u8, field, len) #undef __rel_dynamic_array -#define __rel_dynamic_array(type, item, len) u32 item; +#define __rel_dynamic_array(type, item, len) u32 item; const void *item##_ptr_; #undef __rel_string #define __rel_string(item, src) __rel_dynamic_array(char, item, -1) diff --git a/include/trace/stages/stage5_get_offsets.h b/include/trace/stages/stage5_get_offsets.h index e30a13be46ba..45f8151cf622 100644 --- a/include/trace/stages/stage5_get_offsets.h +++ b/include/trace/stages/stage5_get_offsets.h @@ -47,10 +47,12 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, \ - strlen((src) ? (const char *)(src) : "(null)") + 1) + strlen((src) ? (const char *)(src) : "(null)") + 1) \ + __data_offsets->item##_ptr_ = src; #undef __string_len -#define __string_len(item, src, len) __dynamic_array(char, item, (len) + 1) +#define __string_len(item, src, len) __dynamic_array(char, item, (len) + 1)\ + __data_offsets->item##_ptr_ = src; #undef __vstring #define __vstring(item, fmt, ap) __dynamic_array(char, item, \ @@ -67,11 +69,14 @@ __data_size += __item_length; #undef __rel_string -#define __rel_string(item, src) __rel_dynamic_array(char, item, \ - strlen((src) ? (const char *)(src) : "(null)") + 1) +#define __rel_string(item, src) __rel_dynamic_array(char, item, \ + strlen((src) ? (const char *)(src) : "(null)") + 1) \ + __data_offsets->item##_ptr_ = src; #undef __rel_string_len -#define __rel_string_len(item, src, len) __rel_dynamic_array(char, item, (len) + 1) +#define __rel_string_len(item, src, len) __rel_dynamic_array(char, item, (len) + 1)\ + __data_offsets->item##_ptr_ = src; + /* * __bitmask_size_in_bytes_raw is the number of bytes needed to hold * num_possible_cpus(). diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index 919b1a4da980..b3e2f321e787 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -32,12 +32,14 @@ #undef __assign_str #define __assign_str(dst, src) \ - strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)"); + strcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)") #undef __assign_str_len #define __assign_str_len(dst, src, len) \ do { \ - memcpy(__get_str(dst), (src), (len)); \ + memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)", len); \ __get_str(dst)[len] = '\0'; \ } while(0) @@ -92,12 +94,14 @@ #undef __assign_rel_str #define __assign_rel_str(dst, src) \ - strcpy(__get_rel_str(dst), (src) ? (const char *)(src) : "(null)"); + strcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)") #undef __assign_rel_str_len #define __assign_rel_str_len(dst, src, len) \ do { \ - memcpy(__get_rel_str(dst), (src), (len)); \ + memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)", len); \ __get_rel_str(dst)[len] = '\0'; \ } while (0) -- cgit v1.2.3 From e8b737bfb16a0d540413173e8d1574e3bf8cc0e9 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Thu, 22 Feb 2024 16:14:17 -0500 Subject: tracing: Do not calculate strlen() twice for __string() fields MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The TRACE_EVENT() macro handles dynamic strings by having: TP_PROTO(struct some_struct *s), TP_ARGS(s), TP_STRUCT__entry( __string(my_string, s->string) ), TP_fast_assign( __assign_str(my_string, s->string); ) TP_printk("%s", __get_str(my_string)) There's even some code that may call a function helper to find the s->string value. The problem with the above is that the work to get the s->string is done twice. Once at the __string() and again in the __assign_str(). The length of the string is calculated via a strlen(), not once, but twice. Once during the __string() macro and again in __assign_str(). But the length is actually already recorded in the data location and here's no reason to call strlen() again. Just use the saved length that was saved in the __string() code for the __assign_str() code. Link: https://lore.kernel.org/linux-trace-kernel/20240222211442.793074999@goodmis.org Cc: Masami Hiramatsu Cc: Mark Rutland Cc: Mathieu Desnoyers Cc: Andrew Morton Cc: Ville Syrjälä Cc: Rodrigo Vivi Cc: Chuck Lever Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage6_event_callback.h | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) (limited to 'include') diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index b3e2f321e787..c0e5d097324e 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -32,8 +32,9 @@ #undef __assign_str #define __assign_str(dst, src) \ - strcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)") + memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)", \ + __get_dynamic_array_len(dst)) #undef __assign_str_len #define __assign_str_len(dst, src, len) \ @@ -94,8 +95,9 @@ #undef __assign_rel_str #define __assign_rel_str(dst, src) \ - strcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)") + memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ + __data_offsets.dst##_ptr_ : "(null)", \ + __get_rel_dynamic_array_len(dst)) #undef __assign_rel_str_len #define __assign_rel_str_len(dst, src, len) \ -- cgit v1.2.3 From 916849860fa9c7d3caeb144cb5dec8831cf23bfc Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Thu, 22 Feb 2024 16:14:18 -0500 Subject: tracing: Use ? : shortcut in trace macros MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Instead of having: #define __assign_str(dst, src) \ memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ __data_offsets.dst##_ptr_ : "(null)", \ __get_dynamic_array_len(dst)) Use the ? : shortcut and compact it down to: #define __assign_str(dst, src) \ memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? : "(null)", \ __get_dynamic_array_len(dst)) Link: https://lore.kernel.org/linux-trace-kernel/20240222211442.949327725@goodmis.org Cc: Masami Hiramatsu Cc: Mark Rutland Cc: Andrew Morton Cc: Ville Syrjälä Cc: Rodrigo Vivi Cc: Chuck Lever Suggested-by: Mathieu Desnoyers Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage5_get_offsets.h | 4 ++-- include/trace/stages/stage6_event_callback.h | 14 ++++++-------- 2 files changed, 8 insertions(+), 10 deletions(-) (limited to 'include') diff --git a/include/trace/stages/stage5_get_offsets.h b/include/trace/stages/stage5_get_offsets.h index 45f8151cf622..20b801ed3fd4 100644 --- a/include/trace/stages/stage5_get_offsets.h +++ b/include/trace/stages/stage5_get_offsets.h @@ -47,7 +47,7 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, \ - strlen((src) ? (const char *)(src) : "(null)") + 1) \ + strlen((const char *)(src) ? : "(null)") + 1) \ __data_offsets->item##_ptr_ = src; #undef __string_len @@ -70,7 +70,7 @@ #undef __rel_string #define __rel_string(item, src) __rel_dynamic_array(char, item, \ - strlen((src) ? (const char *)(src) : "(null)") + 1) \ + strlen((const char *)(src) ? : "(null)") + 1) \ __data_offsets->item##_ptr_ = src; #undef __rel_string_len diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index c0e5d097324e..38732855eadb 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -32,15 +32,14 @@ #undef __assign_str #define __assign_str(dst, src) \ - memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)", \ + memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? : "(null)", \ __get_dynamic_array_len(dst)) #undef __assign_str_len #define __assign_str_len(dst, src, len) \ do { \ - memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)", len); \ + memcpy(__get_str(dst), \ + __data_offsets.dst##_ptr_ ? : "(null)", len); \ __get_str(dst)[len] = '\0'; \ } while(0) @@ -95,15 +94,14 @@ #undef __assign_rel_str #define __assign_rel_str(dst, src) \ - memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)", \ + memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? : "(null)", \ __get_rel_dynamic_array_len(dst)) #undef __assign_rel_str_len #define __assign_rel_str_len(dst, src, len) \ do { \ - memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? \ - __data_offsets.dst##_ptr_ : "(null)", len); \ + memcpy(__get_rel_str(dst), \ + __data_offsets.dst##_ptr_ ? : "(null)", len); \ __get_rel_str(dst)[len] = '\0'; \ } while (0) -- cgit v1.2.3 From 70a6ed553f7d3504febac467cb4a0bae621ba3c6 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Thu, 22 Feb 2024 16:14:19 -0500 Subject: tracing: Use EVENT_NULL_STR macro instead of open coding "(null)" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The TRACE_EVENT macros has some dependency if a __string() field is NULL, where it will save "(null)" as the string. This string is also used by __assign_str(). It's better to create a single macro instead of having something that will not be caught by the compiler if there is an unfortunate typo. Link: https://lore.kernel.org/linux-trace-kernel/20240222211443.106216915@goodmis.org Cc: Masami Hiramatsu Cc: Mark Rutland Cc: Andrew Morton Cc: Ville Syrjälä Cc: Rodrigo Vivi Cc: Chuck Lever Suggested-by: Mathieu Desnoyers Signed-off-by: Steven Rostedt (Google) --- include/linux/trace_events.h | 3 +++ include/trace/events/sunrpc.h | 12 ++++++------ include/trace/stages/stage5_get_offsets.h | 4 ++-- include/trace/stages/stage6_event_callback.h | 8 ++++---- 4 files changed, 15 insertions(+), 12 deletions(-) (limited to 'include') diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index fc6d0af56bb1..6f9bdfb09d1d 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -17,6 +17,9 @@ struct dentry; struct bpf_prog; union bpf_attr; +/* Used for event string fields when they are NULL */ +#define EVENT_NULL_STR "(null)" + const char *trace_print_flags_seq(struct trace_seq *p, const char *delim, unsigned long flags, const struct trace_print_flags *flag_array); diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index cdd3a45e6003..ce6a85b82afa 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -1327,18 +1327,18 @@ TRACE_EVENT(xs_stream_read_data, __field(ssize_t, err) __field(size_t, total) __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] : - "(null)") + EVENT_NULL_STR) __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] : - "(null)") + EVENT_NULL_STR) ), TP_fast_assign( __entry->err = err; __entry->total = total; __assign_str(addr, xprt ? - xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)"); + xprt->address_strings[RPC_DISPLAY_ADDR] : EVENT_NULL_STR); __assign_str(port, xprt ? - xprt->address_strings[RPC_DISPLAY_PORT] : "(null)"); + xprt->address_strings[RPC_DISPLAY_PORT] : EVENT_NULL_STR); ), TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr), @@ -1783,7 +1783,7 @@ TRACE_EVENT(svc_process, __string(service, name) __string(procedure, svc_proc_name(rqst)) __string(addr, rqst->rq_xprt ? - rqst->rq_xprt->xpt_remotebuf : "(null)") + rqst->rq_xprt->xpt_remotebuf : EVENT_NULL_STR) ), TP_fast_assign( @@ -1793,7 +1793,7 @@ TRACE_EVENT(svc_process, __assign_str(service, name); __assign_str(procedure, svc_proc_name(rqst)); __assign_str(addr, rqst->rq_xprt ? - rqst->rq_xprt->xpt_remotebuf : "(null)"); + rqst->rq_xprt->xpt_remotebuf : EVENT_NULL_STR); ), TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%s", diff --git a/include/trace/stages/stage5_get_offsets.h b/include/trace/stages/stage5_get_offsets.h index 20b801ed3fd4..e6b96608f452 100644 --- a/include/trace/stages/stage5_get_offsets.h +++ b/include/trace/stages/stage5_get_offsets.h @@ -47,7 +47,7 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, \ - strlen((const char *)(src) ? : "(null)") + 1) \ + strlen((const char *)(src) ? : EVENT_NULL_STR) + 1) \ __data_offsets->item##_ptr_ = src; #undef __string_len @@ -70,7 +70,7 @@ #undef __rel_string #define __rel_string(item, src) __rel_dynamic_array(char, item, \ - strlen((const char *)(src) ? : "(null)") + 1) \ + strlen((const char *)(src) ? : EVENT_NULL_STR) + 1) \ __data_offsets->item##_ptr_ = src; #undef __rel_string_len diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index 38732855eadb..2bfd49713b42 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -32,14 +32,14 @@ #undef __assign_str #define __assign_str(dst, src) \ - memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? : "(null)", \ + memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, \ __get_dynamic_array_len(dst)) #undef __assign_str_len #define __assign_str_len(dst, src, len) \ do { \ memcpy(__get_str(dst), \ - __data_offsets.dst##_ptr_ ? : "(null)", len); \ + __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, len); \ __get_str(dst)[len] = '\0'; \ } while(0) @@ -94,14 +94,14 @@ #undef __assign_rel_str #define __assign_rel_str(dst, src) \ - memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? : "(null)", \ + memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, \ __get_rel_dynamic_array_len(dst)) #undef __assign_rel_str_len #define __assign_rel_str_len(dst, src, len) \ do { \ memcpy(__get_rel_str(dst), \ - __data_offsets.dst##_ptr_ ? : "(null)", len); \ + __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, len); \ __get_rel_str(dst)[len] = '\0'; \ } while (0) -- cgit v1.2.3 From c759e609030ca37e59866cbc849fdc611cc56292 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Fri, 23 Feb 2024 15:22:06 -0500 Subject: tracing: Remove __assign_str_len() Now that __assign_str() gets the length from the __string() (and __string_len()) macros, there's no reason to have a separate __assign_str_len() macro as __assign_str() can get the length of the string needed. Also remove __assign_rel_str() although it had no users anyway. Link: https://lore.kernel.org/linux-trace-kernel/20240223152206.0b650659@gandalf.local.home Cc: Jeff Layton Acked-by: Chuck Lever Signed-off-by: Steven Rostedt (Google) --- fs/nfsd/trace.h | 8 ++++---- include/trace/stages/stage6_event_callback.h | 28 +++++++++++----------------- samples/trace_events/trace-events-sample.h | 9 +++++---- 3 files changed, 20 insertions(+), 25 deletions(-) (limited to 'include') diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h index 288a796b2878..1cd2076210b1 100644 --- a/fs/nfsd/trace.h +++ b/fs/nfsd/trace.h @@ -104,7 +104,7 @@ TRACE_EVENT(nfsd_compound, TP_fast_assign( __entry->xid = be32_to_cpu(rqst->rq_xid); __entry->opcnt = opcnt; - __assign_str_len(tag, tag, taglen); + __assign_str(tag, tag); ), TP_printk("xid=0x%08x opcnt=%u tag=%s", __entry->xid, __entry->opcnt, __get_str(tag) @@ -485,7 +485,7 @@ TRACE_EVENT(nfsd_dirent, TP_fast_assign( __entry->fh_hash = fhp ? knfsd_fh_hash(&fhp->fh_handle) : 0; __entry->ino = ino; - __assign_str_len(name, name, namlen) + __assign_str(name, name); ), TP_printk("fh_hash=0x%08x ino=%llu name=%s", __entry->fh_hash, __entry->ino, __get_str(name) @@ -906,7 +906,7 @@ DECLARE_EVENT_CLASS(nfsd_clid_class, __entry->flavor = clp->cl_cred.cr_flavor; memcpy(__entry->verifier, (void *)&clp->cl_verifier, NFS4_VERIFIER_SIZE); - __assign_str_len(name, clp->cl_name.data, clp->cl_name.len); + __assign_str(name, clp->cl_name.data); ), TP_printk("addr=%pISpc name='%s' verifier=0x%s flavor=%s client=%08x:%08x", __entry->addr, __get_str(name), @@ -1976,7 +1976,7 @@ TRACE_EVENT(nfsd_ctl_time, TP_fast_assign( __entry->netns_ino = net->ns.inum; __entry->time = time; - __assign_str_len(name, name, namelen); + __assign_str(name, name); ), TP_printk("file=%s time=%d\n", __get_str(name), __entry->time diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index 2bfd49713b42..0c0f50bcdc56 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -32,16 +32,13 @@ #undef __assign_str #define __assign_str(dst, src) \ - memcpy(__get_str(dst), __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, \ - __get_dynamic_array_len(dst)) - -#undef __assign_str_len -#define __assign_str_len(dst, src, len) \ do { \ - memcpy(__get_str(dst), \ - __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, len); \ - __get_str(dst)[len] = '\0'; \ - } while(0) + char *__str__ = __get_str(dst); \ + int __len__ = __get_dynamic_array_len(dst) - 1; \ + memcpy(__str__, __data_offsets.dst##_ptr_ ? : \ + EVENT_NULL_STR, __len__); \ + __str__[__len__] = '\0'; \ + } while (0) #undef __assign_vstr #define __assign_vstr(dst, fmt, va) \ @@ -94,15 +91,12 @@ #undef __assign_rel_str #define __assign_rel_str(dst, src) \ - memcpy(__get_rel_str(dst), __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, \ - __get_rel_dynamic_array_len(dst)) - -#undef __assign_rel_str_len -#define __assign_rel_str_len(dst, src, len) \ do { \ - memcpy(__get_rel_str(dst), \ - __data_offsets.dst##_ptr_ ? : EVENT_NULL_STR, len); \ - __get_rel_str(dst)[len] = '\0'; \ + char *__str__ = __get_rel_str(dst); \ + int __len__ = __get_rel_dynamic_array_len(dst) - 1; \ + memcpy(__str__, __data_offsets.dst##_ptr_ ? : \ + EVENT_NULL_STR, __len__); \ + __str__[__len__] = '\0'; \ } while (0) #undef __rel_bitmask diff --git a/samples/trace_events/trace-events-sample.h b/samples/trace_events/trace-events-sample.h index 23f923ccd529..f2d2d56ce8e2 100644 --- a/samples/trace_events/trace-events-sample.h +++ b/samples/trace_events/trace-events-sample.h @@ -163,8 +163,7 @@ * __string(). * * __string_len: This is a helper to a __dynamic_array, but it understands - * that the array has characters in it, and with the combined - * use of __assign_str_len(), it will allocate 'len' + 1 bytes + * that the array has characters in it, it will allocate 'len' + 1 bytes * in the ring buffer and add a '\0' to the string. This is * useful if the string being saved has no terminating '\0' byte. * It requires that the length of the string is known as it acts @@ -174,9 +173,11 @@ * * __string_len(foo, bar, len) * - * To assign this string, use the helper macro __assign_str_len(). + * To assign this string, use the helper macro __assign_str(). + * The length is saved via the __string_len() and is retrieved in + * __assign_str(). * - * __assign_str_len(foo, bar, len); + * __assign_str(foo, bar); * * Then len + 1 is allocated to the ring buffer, and a nul terminating * byte is added. This is similar to: -- cgit v1.2.3 From cf986e57d606849288eecf572800f2bd476fb1ab Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Fri, 23 Feb 2024 16:13:56 -0500 Subject: tracing: Add warning if string in __assign_str() does not match __string() In preparation to remove the second parameter of __assign_str(), make sure it is really a duplicate of __string() by adding a WARN_ON_ONCE(). Link: https://lore.kernel.org/linux-trace-kernel/20240223161356.63b72403@gandalf.local.home Cc: Mathieu Desnoyers Reviewed-by: Masami Hiramatsu (Google) Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage6_event_callback.h | 1 + 1 file changed, 1 insertion(+) (limited to 'include') diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index 0c0f50bcdc56..935608971899 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -35,6 +35,7 @@ do { \ char *__str__ = __get_str(dst); \ int __len__ = __get_dynamic_array_len(dst) - 1; \ + WARN_ON_ONCE((src) != __data_offsets.dst##_ptr_); \ memcpy(__str__, __data_offsets.dst##_ptr_ ? : \ EVENT_NULL_STR, __len__); \ __str__[__len__] = '\0'; \ -- cgit v1.2.3 From 0bdfb68c845edd7e2dbe815266bb09641576e22f Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Fri, 23 Feb 2024 16:25:19 -0500 Subject: tracing: Remove second parameter to __assign_rel_str() The second parameter of __assign_rel_str() is no longer used. It can be removed. Note, the only real users of rel_string is user events. This code is just in the sample code for testing purposes. This makes __assign_rel_str() different than __assign_str() but that's fine. __assign_str() is used over 700 places and has a larger impact. That change will come later. Link: https://lore.kernel.org/linux-trace-kernel/20240223162519.2beb8112@gandalf.local.home Cc: Mathieu Desnoyers Reviewed-by: Masami Hiramatsu (Google) Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage6_event_callback.h | 2 +- samples/trace_events/trace-events-sample.h | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) (limited to 'include') diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index 935608971899..a0c15f67eabe 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -91,7 +91,7 @@ #define __rel_string_len(item, src, len) __rel_dynamic_array(char, item, -1) #undef __assign_rel_str -#define __assign_rel_str(dst, src) \ +#define __assign_rel_str(dst) \ do { \ char *__str__ = __get_rel_str(dst); \ int __len__ = __get_rel_dynamic_array_len(dst) - 1; \ diff --git a/samples/trace_events/trace-events-sample.h b/samples/trace_events/trace-events-sample.h index 2dfaf7fc7bfa..500981eca74d 100644 --- a/samples/trace_events/trace-events-sample.h +++ b/samples/trace_events/trace-events-sample.h @@ -574,7 +574,7 @@ TRACE_EVENT(foo_rel_loc, ), TP_fast_assign( - __assign_rel_str(foo, foo); + __assign_rel_str(foo); __entry->bar = bar; __assign_rel_bitmask(bitmask, mask, BITS_PER_BYTE * sizeof(unsigned long)); -- cgit v1.2.3 From 19f0423fd55c301c8edaea286e568ec657f42750 Mon Sep 17 00:00:00 2001 From: Huang Yiwei Date: Fri, 23 Feb 2024 16:31:26 +0800 Subject: tracing: Support to dump instance traces by ftrace_dump_on_oops Currently ftrace only dumps the global trace buffer on an OOPs. For debugging a production usecase, instance trace will be helpful to check specific problems since global trace buffer may be used for other purposes. This patch extend the ftrace_dump_on_oops parameter to dump a specific or multiple trace instances: - ftrace_dump_on_oops=0: as before -- don't dump - ftrace_dump_on_oops[=1]: as before -- dump the global trace buffer on all CPUs - ftrace_dump_on_oops=2 or =orig_cpu: as before -- dump the global trace buffer on CPU that triggered the oops - ftrace_dump_on_oops=: new behavior -- dump the tracing instance matching - ftrace_dump_on_oops[=2/orig_cpu],[=2/orig_cpu], [=2/orig_cpu]: new behavior -- dump the global trace buffer and multiple instance buffer on all CPUs, or only dump on CPU that triggered the oops if =2 or =orig_cpu is given Also, the sysctl node can handle the input accordingly. Link: https://lore.kernel.org/linux-trace-kernel/20240223083126.1817731-1-quic_hyiwei@quicinc.com Cc: Ross Zwisler Cc: Cc: Cc: Cc: Cc: Cc: Cc: Signed-off-by: Huang Yiwei Signed-off-by: Steven Rostedt (Google) --- Documentation/admin-guide/kernel-parameters.txt | 26 +++- Documentation/admin-guide/sysctl/kernel.rst | 30 ++++- include/linux/ftrace.h | 4 +- include/linux/kernel.h | 1 + kernel/sysctl.c | 4 +- kernel/trace/trace.c | 156 ++++++++++++++++++------ kernel/trace/trace_selftest.c | 2 +- 7 files changed, 168 insertions(+), 55 deletions(-) (limited to 'include') diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt index 479ff1737c2f..fa871d53641c 100644 --- a/Documentation/admin-guide/kernel-parameters.txt +++ b/Documentation/admin-guide/kernel-parameters.txt @@ -1572,12 +1572,28 @@ The above will cause the "foo" tracing instance to trigger a snapshot at the end of boot up. - ftrace_dump_on_oops[=orig_cpu] + ftrace_dump_on_oops[=2(orig_cpu) | =][, | + ,=2(orig_cpu)] [FTRACE] will dump the trace buffers on oops. - If no parameter is passed, ftrace will dump - buffers of all CPUs, but if you pass orig_cpu, it will - dump only the buffer of the CPU that triggered the - oops. + If no parameter is passed, ftrace will dump global + buffers of all CPUs, if you pass 2 or orig_cpu, it + will dump only the buffer of the CPU that triggered + the oops, or the specific instance will be dumped if + its name is passed. Multiple instance dump is also + supported, and instances are separated by commas. Each + instance supports only dump on CPU that triggered the + oops by passing 2 or orig_cpu to it. + + ftrace_dump_on_oops=foo=orig_cpu + + The above will dump only the buffer of "foo" instance + on CPU that triggered the oops. + + ftrace_dump_on_oops,foo,bar=orig_cpu + + The above will dump global buffer on all CPUs, the + buffer of "foo" instance on all CPUs and the buffer + of "bar" instance on CPU that triggered the oops. ftrace_filter=[function-list] [FTRACE] Limit the functions traced by the function diff --git a/Documentation/admin-guide/sysctl/kernel.rst b/Documentation/admin-guide/sysctl/kernel.rst index 6584a1f9bfe3..ea8e5f152edc 100644 --- a/Documentation/admin-guide/sysctl/kernel.rst +++ b/Documentation/admin-guide/sysctl/kernel.rst @@ -296,12 +296,30 @@ kernel panic). This will output the contents of the ftrace buffers to the console. This is very useful for capturing traces that lead to crashes and outputting them to a serial console. -= =================================================== -0 Disabled (default). -1 Dump buffers of all CPUs. -2 Dump the buffer of the CPU that triggered the oops. -= =================================================== - +======================= =========================================== +0 Disabled (default). +1 Dump buffers of all CPUs. +2(orig_cpu) Dump the buffer of the CPU that triggered the + oops. + Dump the specific instance buffer on all CPUs. +=2(orig_cpu) Dump the specific instance buffer on the CPU + that triggered the oops. +======================= =========================================== + +Multiple instance dump is also supported, and instances are separated +by commas. If global buffer also needs to be dumped, please specify +the dump mode (1/2/orig_cpu) first for global buffer. + +So for example to dump "foo" and "bar" instance buffer on all CPUs, +user can:: + + echo "foo,bar" > /proc/sys/kernel/ftrace_dump_on_oops + +To dump global buffer and "foo" instance buffer on all +CPUs along with the "bar" instance buffer on CPU that triggered the +oops, user can:: + + echo "1,foo,bar=2" > /proc/sys/kernel/ftrace_dump_on_oops ftrace_enabled, stack_tracer_enabled ==================================== diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h index e8921871ef9a..54d53f345d14 100644 --- a/include/linux/ftrace.h +++ b/include/linux/ftrace.h @@ -1151,7 +1151,9 @@ static inline void unpause_graph_tracing(void) { } #ifdef CONFIG_TRACING enum ftrace_dump_mode; -extern enum ftrace_dump_mode ftrace_dump_on_oops; +#define MAX_TRACER_SIZE 100 +extern char ftrace_dump_on_oops[]; +extern int ftrace_dump_on_oops_enabled(void); extern int tracepoint_printk; extern void disable_trace_on_warning(void); diff --git a/include/linux/kernel.h b/include/linux/kernel.h index d718fbec72dd..be2e8c0a187e 100644 --- a/include/linux/kernel.h +++ b/include/linux/kernel.h @@ -215,6 +215,7 @@ enum ftrace_dump_mode { DUMP_NONE, DUMP_ALL, DUMP_ORIG, + DUMP_PARAM, }; #ifdef CONFIG_TRACING diff --git a/kernel/sysctl.c b/kernel/sysctl.c index 157f7ce2942d..81cc974913bb 100644 --- a/kernel/sysctl.c +++ b/kernel/sysctl.c @@ -1710,9 +1710,9 @@ static struct ctl_table kern_table[] = { { .procname = "ftrace_dump_on_oops", .data = &ftrace_dump_on_oops, - .maxlen = sizeof(int), + .maxlen = MAX_TRACER_SIZE, .mode = 0644, - .proc_handler = proc_dointvec, + .proc_handler = proc_dostring, }, { .procname = "traceoff_on_warning", diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 1e1fd377a1cf..233d1af39fff 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -130,9 +130,12 @@ cpumask_var_t __read_mostly tracing_buffer_mask; * /proc/sys/kernel/ftrace_dump_on_oops * Set 1 if you want to dump buffers of all CPUs * Set 2 if you want to dump the buffer of the CPU that triggered oops + * Set instance name if you want to dump the specific trace instance + * Multiple instance dump is also supported, and instances are seperated + * by commas. */ - -enum ftrace_dump_mode ftrace_dump_on_oops; +/* Set to string format zero to disable by default */ +char ftrace_dump_on_oops[MAX_TRACER_SIZE] = "0"; /* When set, tracing will stop when a WARN*() is hit */ int __disable_trace_on_warning; @@ -178,7 +181,6 @@ static void ftrace_trace_userstack(struct trace_array *tr, struct trace_buffer *buffer, unsigned int trace_ctx); -#define MAX_TRACER_SIZE 100 static char bootup_tracer_buf[MAX_TRACER_SIZE] __initdata; static char *default_bootup_tracer; @@ -201,19 +203,33 @@ static int __init set_cmdline_ftrace(char *str) } __setup("ftrace=", set_cmdline_ftrace); +int ftrace_dump_on_oops_enabled(void) +{ + if (!strcmp("0", ftrace_dump_on_oops)) + return 0; + else + return 1; +} + static int __init set_ftrace_dump_on_oops(char *str) { - if (*str++ != '=' || !*str || !strcmp("1", str)) { - ftrace_dump_on_oops = DUMP_ALL; + if (!*str) { + strscpy(ftrace_dump_on_oops, "1", MAX_TRACER_SIZE); return 1; } - if (!strcmp("orig_cpu", str) || !strcmp("2", str)) { - ftrace_dump_on_oops = DUMP_ORIG; - return 1; - } + if (*str == ',') { + strscpy(ftrace_dump_on_oops, "1", MAX_TRACER_SIZE); + strscpy(ftrace_dump_on_oops + 1, str, MAX_TRACER_SIZE - 1); + return 1; + } + + if (*str++ == '=') { + strscpy(ftrace_dump_on_oops, str, MAX_TRACER_SIZE); + return 1; + } - return 0; + return 0; } __setup("ftrace_dump_on_oops", set_ftrace_dump_on_oops); @@ -9832,14 +9848,14 @@ static struct notifier_block trace_die_notifier = { static int trace_die_panic_handler(struct notifier_block *self, unsigned long ev, void *unused) { - if (!ftrace_dump_on_oops) + if (!ftrace_dump_on_oops_enabled()) return NOTIFY_DONE; /* The die notifier requires DIE_OOPS to trigger */ if (self == &trace_die_notifier && ev != DIE_OOPS) return NOTIFY_DONE; - ftrace_dump(ftrace_dump_on_oops); + ftrace_dump(DUMP_PARAM); return NOTIFY_DONE; } @@ -9880,12 +9896,12 @@ trace_printk_seq(struct trace_seq *s) trace_seq_init(s); } -void trace_init_global_iter(struct trace_iterator *iter) +static void trace_init_iter(struct trace_iterator *iter, struct trace_array *tr) { - iter->tr = &global_trace; + iter->tr = tr; iter->trace = iter->tr->current_trace; iter->cpu_file = RING_BUFFER_ALL_CPUS; - iter->array_buffer = &global_trace.array_buffer; + iter->array_buffer = &tr->array_buffer; if (iter->trace && iter->trace->open) iter->trace->open(iter); @@ -9905,22 +9921,19 @@ void trace_init_global_iter(struct trace_iterator *iter) iter->fmt_size = STATIC_FMT_BUF_SIZE; } -void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) +void trace_init_global_iter(struct trace_iterator *iter) +{ + trace_init_iter(iter, &global_trace); +} + +static void ftrace_dump_one(struct trace_array *tr, enum ftrace_dump_mode dump_mode) { /* use static because iter can be a bit big for the stack */ static struct trace_iterator iter; - static atomic_t dump_running; - struct trace_array *tr = &global_trace; unsigned int old_userobj; unsigned long flags; int cnt = 0, cpu; - /* Only allow one dump user at a time. */ - if (atomic_inc_return(&dump_running) != 1) { - atomic_dec(&dump_running); - return; - } - /* * Always turn off tracing when we dump. * We don't need to show trace output of what happens @@ -9929,12 +9942,12 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) * If the user does a sysrq-z, then they can re-enable * tracing with echo 1 > tracing_on. */ - tracing_off(); + tracer_tracing_off(tr); local_irq_save(flags); /* Simulate the iterator */ - trace_init_global_iter(&iter); + trace_init_iter(&iter, tr); for_each_tracing_cpu(cpu) { atomic_inc(&per_cpu_ptr(iter.array_buffer->data, cpu)->disabled); @@ -9945,21 +9958,15 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) /* don't look at user memory in panic mode */ tr->trace_flags &= ~TRACE_ITER_SYM_USEROBJ; - switch (oops_dump_mode) { - case DUMP_ALL: - iter.cpu_file = RING_BUFFER_ALL_CPUS; - break; - case DUMP_ORIG: + if (dump_mode == DUMP_ORIG) iter.cpu_file = raw_smp_processor_id(); - break; - case DUMP_NONE: - goto out_enable; - default: - printk(KERN_TRACE "Bad dumping mode, switching to all CPUs dump\n"); + else iter.cpu_file = RING_BUFFER_ALL_CPUS; - } - printk(KERN_TRACE "Dumping ftrace buffer:\n"); + if (tr == &global_trace) + printk(KERN_TRACE "Dumping ftrace buffer:\n"); + else + printk(KERN_TRACE "Dumping ftrace instance %s buffer:\n", tr->name); /* Did function tracer already get disabled? */ if (ftrace_is_dead()) { @@ -10001,15 +10008,84 @@ void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) else printk(KERN_TRACE "---------------------------------\n"); - out_enable: tr->trace_flags |= old_userobj; for_each_tracing_cpu(cpu) { atomic_dec(&per_cpu_ptr(iter.array_buffer->data, cpu)->disabled); } - atomic_dec(&dump_running); local_irq_restore(flags); } + +static void ftrace_dump_by_param(void) +{ + bool first_param = true; + char dump_param[MAX_TRACER_SIZE]; + char *buf, *token, *inst_name; + struct trace_array *tr; + + strscpy(dump_param, ftrace_dump_on_oops, MAX_TRACER_SIZE); + buf = dump_param; + + while ((token = strsep(&buf, ",")) != NULL) { + if (first_param) { + first_param = false; + if (!strcmp("0", token)) + continue; + else if (!strcmp("1", token)) { + ftrace_dump_one(&global_trace, DUMP_ALL); + continue; + } + else if (!strcmp("2", token) || + !strcmp("orig_cpu", token)) { + ftrace_dump_one(&global_trace, DUMP_ORIG); + continue; + } + } + + inst_name = strsep(&token, "="); + tr = trace_array_find(inst_name); + if (!tr) { + printk(KERN_TRACE "Instance %s not found\n", inst_name); + continue; + } + + if (token && (!strcmp("2", token) || + !strcmp("orig_cpu", token))) + ftrace_dump_one(tr, DUMP_ORIG); + else + ftrace_dump_one(tr, DUMP_ALL); + } +} + +void ftrace_dump(enum ftrace_dump_mode oops_dump_mode) +{ + static atomic_t dump_running; + + /* Only allow one dump user at a time. */ + if (atomic_inc_return(&dump_running) != 1) { + atomic_dec(&dump_running); + return; + } + + switch (oops_dump_mode) { + case DUMP_ALL: + ftrace_dump_one(&global_trace, DUMP_ALL); + break; + case DUMP_ORIG: + ftrace_dump_one(&global_trace, DUMP_ORIG); + break; + case DUMP_PARAM: + ftrace_dump_by_param(); + break; + case DUMP_NONE: + break; + default: + printk(KERN_TRACE "Bad dumping mode, switching to all CPUs dump\n"); + ftrace_dump_one(&global_trace, DUMP_ALL); + } + + atomic_dec(&dump_running); +} EXPORT_SYMBOL_GPL(ftrace_dump); #define WRITE_BUFSIZE 4096 diff --git a/kernel/trace/trace_selftest.c b/kernel/trace/trace_selftest.c index 529590499b1f..e9c5058a8efd 100644 --- a/kernel/trace/trace_selftest.c +++ b/kernel/trace/trace_selftest.c @@ -768,7 +768,7 @@ static int trace_graph_entry_watchdog(struct ftrace_graph_ent *trace) if (unlikely(++graph_hang_thresh > GRAPH_MAX_FUNC_TEST)) { ftrace_graph_stop(); printk(KERN_WARNING "BUG: Function graph tracer hang!\n"); - if (ftrace_dump_on_oops) { + if (ftrace_dump_on_oops_enabled()) { ftrace_dump(DUMP_ALL); /* ftrace_dump() disables tracing */ tracing_on(); -- cgit v1.2.3 From 1b273124107cc8b9dd52228eba701efa516a3d92 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Wed, 28 Feb 2024 13:31:12 -0500 Subject: tracepoints: Use WARN() and not WARN_ON() for warnings There are two WARN_ON*() warnings in tracepoint.h that deal with RCU usage. But when they trigger, especially from using a TRACE_EVENT() macro, the information is not very helpful and is confusing: ------------[ cut here ]------------ WARNING: CPU: 0 PID: 0 at include/trace/events/lock.h:24 lock_acquire+0x2b2/0x2d0 Where the above warning takes you to: TRACE_EVENT(lock_acquire, <<<--- line 24 in lock.h TP_PROTO(struct lockdep_map *lock, unsigned int subclass, int trylock, int read, int check, struct lockdep_map *next_lock, unsigned long ip), [..] Change the WARN_ON_ONCE() to WARN_ONCE() and add a string that allows someone to search for exactly where the bug happened. Link: https://lore.kernel.org/linux-trace-kernel/20240228133112.0d64fb1b@gandalf.local.home Cc: Masami Hiramatsu Cc: Mathieu Desnoyers Cc: Thomas Gleixner Reported-by: Borislav Petkov Tested-by: Borislav Petkov (AMD) Reviewed-by: Paul E. McKenney Signed-off-by: Steven Rostedt (Google) --- include/linux/tracepoint.h | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'include') diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h index 88c0ba623ee6..689b6d71590e 100644 --- a/include/linux/tracepoint.h +++ b/include/linux/tracepoint.h @@ -199,7 +199,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p) if (!(cond)) \ return; \ \ - if (WARN_ON_ONCE(RCUIDLE_COND(rcuidle))) \ + if (WARN_ONCE(RCUIDLE_COND(rcuidle), \ + "Bad RCU usage for tracepoint")) \ return; \ \ /* keep srcu and sched-rcu usage consistent */ \ @@ -259,7 +260,8 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p) TP_ARGS(args), \ TP_CONDITION(cond), 0); \ if (IS_ENABLED(CONFIG_LOCKDEP) && (cond)) { \ - WARN_ON_ONCE(!rcu_is_watching()); \ + WARN_ONCE(!rcu_is_watching(), \ + "RCU not watching for tracepoint"); \ } \ } \ __DECLARE_TRACE_RCU(name, PARAMS(proto), PARAMS(args), \ -- cgit v1.2.3 From b1afefa62ca9d77c8b1d386c3512fb4f21cb7db1 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 12 Mar 2024 11:30:02 -0400 Subject: tracing: Use strcmp() in __assign_str() WARN_ON() check The WARN_ON() check in __assign_str() to catch where the source variable to the macro doesn't match the source variable to __string() gives an error in clang: >> include/trace/events/sunrpc.h:703:4: warning: result of comparison against a string literal is unspecified (use an explicit string comparison function instead) [-Wstring-compare] 670 | __assign_str(progname, "unknown"); That's because the __assign_str() macro has: WARN_ON_ONCE((src) != __data_offsets.dst##_ptr_); Where "src" is a string literal. Clang warns when comparing a string literal directly as it is undefined to what the value of the literal is. Since this is still to make sure the same string that goes to __string() is the same as __assign_str(), for string literals do a test for that and then use strcmp() in those cases Note that this depends on commit 51270d573a8d ("tracing/net_sched: Fix tracepoints that save qdisc_dev() as a string") being applied, as this was what found that bug. Link: https://lore.kernel.org/linux-trace-kernel/20240312113002.00031668@gandalf.local.home Cc: Masami Hiramatsu Cc: Mathieu Desnoyers Cc: Nathan Chancellor Reported-by: kernel test robot Closes: https://lore.kernel.org/oe-kbuild-all/202402292111.KIdExylU-lkp@intel.com/ Fixes: 433e1d88a3be ("tracing: Add warning if string in __assign_str() does not match __string()") Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage6_event_callback.h | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'include') diff --git a/include/trace/stages/stage6_event_callback.h b/include/trace/stages/stage6_event_callback.h index a0c15f67eabe..83da83a0c14f 100644 --- a/include/trace/stages/stage6_event_callback.h +++ b/include/trace/stages/stage6_event_callback.h @@ -35,7 +35,9 @@ do { \ char *__str__ = __get_str(dst); \ int __len__ = __get_dynamic_array_len(dst) - 1; \ - WARN_ON_ONCE((src) != __data_offsets.dst##_ptr_); \ + WARN_ON_ONCE(__builtin_constant_p(src) ? \ + strcmp((src), __data_offsets.dst##_ptr_) : \ + (src) != __data_offsets.dst##_ptr_); \ memcpy(__str__, __data_offsets.dst##_ptr_ ? : \ EVENT_NULL_STR, __len__); \ __str__[__len__] = '\0'; \ -- cgit v1.2.3 From 7604256cecef34a82333d9f78262d3180f4eb525 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Thu, 14 Mar 2024 23:27:54 -0400 Subject: tracing: Add __string_src() helper to help compilers not to get confused The __string() helper macro of the TRACE_EVENT() macro is used to determine how much of the ring buffer needs to be allocated to fit the given source string. Some trace events have a string that is dependent on another variable that could be NULL, and in those cases the string is passed in to be NULL. The __string() macro can handle being passed in a NULL pointer for which it will turn it into "(null)". It does that with: strlen((src) ? (const char *)(src) : "(null)") + 1 But if src itself has the same conditional type it can confuse the compiler. That is: __string(r ? dev(r)->name : NULL) Would turn into: strlen((r ? dev(r)->name : NULL) ? (r ? dev(r)->name : NULL) : "(null)" + 1 For which the compiler thinks that NULL is being passed to strlen() and gives this kind of warning: ./include/trace/stages/stage5_get_offsets.h:50:21: warning: argument 1 null where non-null expected [-Wnonnull] 50 | strlen((src) ? (const char *)(src) : "(null)") + 1) Instead, create a static inline function that takes the src string and will return the string if it is not NULL and will return "(null)" if it is. This will then make the strlen() line: strlen(__string_src(src)) + 1 Where the compiler can see that strlen() will not end up with NULL and does not warn about it. Note that this depends on commit 51270d573a8d ("tracing/net_sched: Fix tracepoints that save qdisc_dev() as a string") being applied, as passing the qdisc_dev() into __string_src() will give an error. Link: https://lore.kernel.org/all/ZfNmfCmgCs4Nc+EH@aschofie-mobl2/ Link: https://lore.kernel.org/linux-trace-kernel/20240314232754.345cea82@rorschach.local.home Cc: Masami Hiramatsu Cc: Mathieu Desnoyers Reported-by: Alison Schofield Signed-off-by: Steven Rostedt (Google) --- include/trace/stages/stage5_get_offsets.h | 14 ++++++++++++-- 1 file changed, 12 insertions(+), 2 deletions(-) (limited to 'include') diff --git a/include/trace/stages/stage5_get_offsets.h b/include/trace/stages/stage5_get_offsets.h index e6b96608f452..c6a62dfb18ef 100644 --- a/include/trace/stages/stage5_get_offsets.h +++ b/include/trace/stages/stage5_get_offsets.h @@ -9,6 +9,16 @@ #undef __entry #define __entry entry +#ifndef __STAGE5_STRING_SRC_H +#define __STAGE5_STRING_SRC_H +static inline const char *__string_src(const char *str) +{ + if (!str) + return EVENT_NULL_STR; + return str; +} +#endif /* __STAGE5_STRING_SRC_H */ + /* * Fields should never declare an array: i.e. __field(int, arr[5]) * If they do, it will cause issues in parsing and possibly corrupt the @@ -47,7 +57,7 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, \ - strlen((const char *)(src) ? : EVENT_NULL_STR) + 1) \ + strlen(__string_src(src)) + 1) \ __data_offsets->item##_ptr_ = src; #undef __string_len @@ -70,7 +80,7 @@ #undef __rel_string #define __rel_string(item, src) __rel_dynamic_array(char, item, \ - strlen((const char *)(src) ? : EVENT_NULL_STR) + 1) \ + strlen(__string_src(src)) + 1) \ __data_offsets->item##_ptr_ = src; #undef __rel_string_len -- cgit v1.2.3