From ec43908dd556b2292f028c6e412261689405ba6e Mon Sep 17 00:00:00 2001 From: Menglong Dong Date: Mon, 6 Jun 2022 10:24:35 +0800 Subject: net: skb: use auto-generation to convert skb drop reason to string It is annoying to add new skb drop reasons to 'enum skb_drop_reason' and TRACE_SKB_DROP_REASON in trace/event/skb.h, and it's easy to forget to add the new reasons we added to TRACE_SKB_DROP_REASON. TRACE_SKB_DROP_REASON is used to convert drop reason of type number to string. For now, the string we passed to user space is exactly the same as the name in 'enum skb_drop_reason' with a 'SKB_DROP_REASON_' prefix. Therefore, we can use 'auto-generation' to generate these drop reasons to string at build time. The new source 'dropreason_str.c' will be auto generated during build time, which contains the string array 'const char * const drop_reasons[]'. Signed-off-by: Menglong Dong Signed-off-by: Paolo Abeni --- include/trace/events/skb.h | 89 +--------------------------------------------- 1 file changed, 1 insertion(+), 88 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/skb.h b/include/trace/events/skb.h index a477bf907498..45264e4bb254 100644 --- a/include/trace/events/skb.h +++ b/include/trace/events/skb.h @@ -9,92 +9,6 @@ #include #include -#define TRACE_SKB_DROP_REASON \ - EM(SKB_DROP_REASON_NOT_SPECIFIED, NOT_SPECIFIED) \ - EM(SKB_DROP_REASON_NO_SOCKET, NO_SOCKET) \ - EM(SKB_DROP_REASON_PKT_TOO_SMALL, PKT_TOO_SMALL) \ - EM(SKB_DROP_REASON_TCP_CSUM, TCP_CSUM) \ - EM(SKB_DROP_REASON_SOCKET_FILTER, SOCKET_FILTER) \ - EM(SKB_DROP_REASON_UDP_CSUM, UDP_CSUM) \ - EM(SKB_DROP_REASON_NETFILTER_DROP, NETFILTER_DROP) \ - EM(SKB_DROP_REASON_OTHERHOST, OTHERHOST) \ - EM(SKB_DROP_REASON_IP_CSUM, IP_CSUM) \ - EM(SKB_DROP_REASON_IP_INHDR, IP_INHDR) \ - EM(SKB_DROP_REASON_IP_RPFILTER, IP_RPFILTER) \ - EM(SKB_DROP_REASON_UNICAST_IN_L2_MULTICAST, \ - UNICAST_IN_L2_MULTICAST) \ - EM(SKB_DROP_REASON_XFRM_POLICY, XFRM_POLICY) \ - EM(SKB_DROP_REASON_IP_NOPROTO, IP_NOPROTO) \ - EM(SKB_DROP_REASON_SOCKET_RCVBUFF, SOCKET_RCVBUFF) \ - EM(SKB_DROP_REASON_PROTO_MEM, PROTO_MEM) \ - EM(SKB_DROP_REASON_TCP_MD5NOTFOUND, TCP_MD5NOTFOUND) \ - EM(SKB_DROP_REASON_TCP_MD5UNEXPECTED, \ - TCP_MD5UNEXPECTED) \ - EM(SKB_DROP_REASON_TCP_MD5FAILURE, TCP_MD5FAILURE) \ - EM(SKB_DROP_REASON_SOCKET_BACKLOG, SOCKET_BACKLOG) \ - EM(SKB_DROP_REASON_TCP_FLAGS, TCP_FLAGS) \ - EM(SKB_DROP_REASON_TCP_ZEROWINDOW, TCP_ZEROWINDOW) \ - EM(SKB_DROP_REASON_TCP_OLD_DATA, TCP_OLD_DATA) \ - EM(SKB_DROP_REASON_TCP_OVERWINDOW, TCP_OVERWINDOW) \ - EM(SKB_DROP_REASON_TCP_OFOMERGE, TCP_OFOMERGE) \ - EM(SKB_DROP_REASON_TCP_OFO_DROP, TCP_OFO_DROP) \ - EM(SKB_DROP_REASON_TCP_RFC7323_PAWS, TCP_RFC7323_PAWS) \ - EM(SKB_DROP_REASON_TCP_INVALID_SEQUENCE, \ - TCP_INVALID_SEQUENCE) \ - EM(SKB_DROP_REASON_TCP_RESET, TCP_RESET) \ - EM(SKB_DROP_REASON_TCP_INVALID_SYN, TCP_INVALID_SYN) \ - EM(SKB_DROP_REASON_TCP_CLOSE, TCP_CLOSE) \ - EM(SKB_DROP_REASON_TCP_FASTOPEN, TCP_FASTOPEN) \ - EM(SKB_DROP_REASON_TCP_OLD_ACK, TCP_OLD_ACK) \ - EM(SKB_DROP_REASON_TCP_TOO_OLD_ACK, TCP_TOO_OLD_ACK) \ - EM(SKB_DROP_REASON_TCP_ACK_UNSENT_DATA, \ - TCP_ACK_UNSENT_DATA) \ - EM(SKB_DROP_REASON_TCP_OFO_QUEUE_PRUNE, \ - TCP_OFO_QUEUE_PRUNE) \ - EM(SKB_DROP_REASON_IP_OUTNOROUTES, IP_OUTNOROUTES) \ - EM(SKB_DROP_REASON_BPF_CGROUP_EGRESS, \ - BPF_CGROUP_EGRESS) \ - EM(SKB_DROP_REASON_IPV6DISABLED, IPV6DISABLED) \ - EM(SKB_DROP_REASON_NEIGH_CREATEFAIL, NEIGH_CREATEFAIL) \ - EM(SKB_DROP_REASON_NEIGH_FAILED, NEIGH_FAILED) \ - EM(SKB_DROP_REASON_NEIGH_QUEUEFULL, NEIGH_QUEUEFULL) \ - EM(SKB_DROP_REASON_NEIGH_DEAD, NEIGH_DEAD) \ - EM(SKB_DROP_REASON_TC_EGRESS, TC_EGRESS) \ - EM(SKB_DROP_REASON_QDISC_DROP, QDISC_DROP) \ - EM(SKB_DROP_REASON_CPU_BACKLOG, CPU_BACKLOG) \ - EM(SKB_DROP_REASON_XDP, XDP) \ - EM(SKB_DROP_REASON_TC_INGRESS, TC_INGRESS) \ - EM(SKB_DROP_REASON_UNHANDLED_PROTO, UNHANDLED_PROTO) \ - EM(SKB_DROP_REASON_SKB_CSUM, SKB_CSUM) \ - EM(SKB_DROP_REASON_SKB_GSO_SEG, SKB_GSO_SEG) \ - EM(SKB_DROP_REASON_SKB_UCOPY_FAULT, SKB_UCOPY_FAULT) \ - EM(SKB_DROP_REASON_DEV_HDR, DEV_HDR) \ - EM(SKB_DROP_REASON_DEV_READY, DEV_READY) \ - EM(SKB_DROP_REASON_FULL_RING, FULL_RING) \ - EM(SKB_DROP_REASON_NOMEM, NOMEM) \ - EM(SKB_DROP_REASON_HDR_TRUNC, HDR_TRUNC) \ - EM(SKB_DROP_REASON_TAP_FILTER, TAP_FILTER) \ - EM(SKB_DROP_REASON_TAP_TXFILTER, TAP_TXFILTER) \ - EM(SKB_DROP_REASON_ICMP_CSUM, ICMP_CSUM) \ - EM(SKB_DROP_REASON_INVALID_PROTO, INVALID_PROTO) \ - EM(SKB_DROP_REASON_IP_INADDRERRORS, IP_INADDRERRORS) \ - EM(SKB_DROP_REASON_IP_INNOROUTES, IP_INNOROUTES) \ - EM(SKB_DROP_REASON_PKT_TOO_BIG, PKT_TOO_BIG) \ - EMe(SKB_DROP_REASON_MAX, MAX) - -#undef EM -#undef EMe - -#define EM(a, b) TRACE_DEFINE_ENUM(a); -#define EMe(a, b) TRACE_DEFINE_ENUM(a); - -TRACE_SKB_DROP_REASON - -#undef EM -#undef EMe -#define EM(a, b) { a, #b }, -#define EMe(a, b) { a, #b } - /* * Tracepoint for free an sk_buff: */ @@ -121,8 +35,7 @@ TRACE_EVENT(kfree_skb, TP_printk("skbaddr=%p protocol=%u location=%p reason: %s", __entry->skbaddr, __entry->protocol, __entry->location, - __print_symbolic(__entry->reason, - TRACE_SKB_DROP_REASON)) + drop_reasons[__entry->reason]) ); TRACE_EVENT(consume_skb, -- cgit v1.2.3 From 0da11bf0cab9029db8b85e48d962ff05c00a4faa Mon Sep 17 00:00:00 2001 From: Eiichi Tsukata Date: Fri, 27 May 2022 00:53:45 +0000 Subject: cpuidle: haltpoll: Add trace points for guest_halt_poll_ns grow/shrink Add trace points as are implemented in KVM host halt polling. This helps tune guest halt polling params. Signed-off-by: Eiichi Tsukata Acked-by: Marcelo Tosatti Signed-off-by: Rafael J. Wysocki --- include/trace/events/power.h | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/power.h b/include/trace/events/power.h index af5018aa9517..c708521e4ed5 100644 --- a/include/trace/events/power.h +++ b/include/trace/events/power.h @@ -500,6 +500,35 @@ DEFINE_EVENT(dev_pm_qos_request, dev_pm_qos_remove_request, TP_ARGS(name, type, new_value) ); + +TRACE_EVENT(guest_halt_poll_ns, + + TP_PROTO(bool grow, unsigned int new, unsigned int old), + + TP_ARGS(grow, new, old), + + TP_STRUCT__entry( + __field(bool, grow) + __field(unsigned int, new) + __field(unsigned int, old) + ), + + TP_fast_assign( + __entry->grow = grow; + __entry->new = new; + __entry->old = old; + ), + + TP_printk("halt_poll_ns %u (%s %u)", + __entry->new, + __entry->grow ? "grow" : "shrink", + __entry->old) +); + +#define trace_guest_halt_poll_ns_grow(new, old) \ + trace_guest_halt_poll_ns(true, new, old) +#define trace_guest_halt_poll_ns_shrink(new, old) \ + trace_guest_halt_poll_ns(false, new, old) #endif /* _TRACE_POWER_H */ /* This part must be outside protection */ -- cgit v1.2.3 From d593d64f043add170d8ea9cf698449637917dcf9 Mon Sep 17 00:00:00 2001 From: Prasad Sodagudi Date: Wed, 18 May 2022 22:14:14 +0530 Subject: lib: Add register read/write tracing support Generic MMIO read/write i.e., __raw_{read,write}{b,l,w,q} accessors are typically used to read/write from/to memory mapped registers and can cause hangs or some undefined behaviour in following few cases, * If the access to the register space is unclocked, for example: if there is an access to multimedia(MM) block registers without MM clocks. * If the register space is protected and not set to be accessible from non-secure world, for example: only EL3 (EL: Exception level) access is allowed and any EL2/EL1 access is forbidden. * If xPU(memory/register protection units) is controlling access to certain memory/register space for specific clients. and more... Such cases usually results in instant reboot/SErrors/NOC or interconnect hangs and tracing these register accesses can be very helpful to debug such issues during initial development stages and also in later stages. So use ftrace trace events to log such MMIO register accesses which provides rich feature set such as early enablement of trace events, filtering capability, dumping ftrace logs on console and many more. Sample output: rwmmio_write: __qcom_geni_serial_console_write+0x160/0x1e0 width=32 val=0xa0d5d addr=0xfffffbfffdbff700 rwmmio_post_write: __qcom_geni_serial_console_write+0x160/0x1e0 width=32 val=0xa0d5d addr=0xfffffbfffdbff700 rwmmio_read: qcom_geni_serial_poll_bit+0x94/0x138 width=32 addr=0xfffffbfffdbff610 rwmmio_post_read: qcom_geni_serial_poll_bit+0x94/0x138 width=32 val=0x0 addr=0xfffffbfffdbff610 Co-developed-by: Sai Prakash Ranjan Signed-off-by: Prasad Sodagudi Signed-off-by: Sai Prakash Ranjan Acked-by: Steven Rostedt (Google) Signed-off-by: Arnd Bergmann --- include/trace/events/rwmmio.h | 97 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 97 insertions(+) create mode 100644 include/trace/events/rwmmio.h (limited to 'include/trace/events') diff --git a/include/trace/events/rwmmio.h b/include/trace/events/rwmmio.h new file mode 100644 index 000000000000..de41159216c1 --- /dev/null +++ b/include/trace/events/rwmmio.h @@ -0,0 +1,97 @@ +/* SPDX-License-Identifier: GPL-2.0-only */ +/* + * Copyright (c) 2021-2022 Qualcomm Innovation Center, Inc. All rights reserved. + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM rwmmio + +#if !defined(_TRACE_RWMMIO_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_RWMMIO_H + +#include + +DECLARE_EVENT_CLASS(rwmmio_rw_template, + + TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), + + TP_ARGS(caller, val, width, addr), + + TP_STRUCT__entry( + __field(unsigned long, caller) + __field(unsigned long, addr) + __field(u64, val) + __field(u8, width) + ), + + TP_fast_assign( + __entry->caller = caller; + __entry->val = val; + __entry->addr = (unsigned long)addr; + __entry->width = width; + ), + + TP_printk("%pS width=%d val=%#llx addr=%#lx", + (void *)__entry->caller, __entry->width, + __entry->val, __entry->addr) +); + +DEFINE_EVENT(rwmmio_rw_template, rwmmio_write, + TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), + TP_ARGS(caller, val, width, addr) +); + +DEFINE_EVENT(rwmmio_rw_template, rwmmio_post_write, + TP_PROTO(unsigned long caller, u64 val, u8 width, volatile void __iomem *addr), + TP_ARGS(caller, val, width, addr) +); + +TRACE_EVENT(rwmmio_read, + + TP_PROTO(unsigned long caller, u8 width, const volatile void __iomem *addr), + + TP_ARGS(caller, width, addr), + + TP_STRUCT__entry( + __field(unsigned long, caller) + __field(unsigned long, addr) + __field(u8, width) + ), + + TP_fast_assign( + __entry->caller = caller; + __entry->addr = (unsigned long)addr; + __entry->width = width; + ), + + TP_printk("%pS width=%d addr=%#lx", + (void *)__entry->caller, __entry->width, __entry->addr) +); + +TRACE_EVENT(rwmmio_post_read, + + TP_PROTO(unsigned long caller, u64 val, u8 width, const volatile void __iomem *addr), + + TP_ARGS(caller, val, width, addr), + + TP_STRUCT__entry( + __field(unsigned long, caller) + __field(unsigned long, addr) + __field(u64, val) + __field(u8, width) + ), + + TP_fast_assign( + __entry->caller = caller; + __entry->val = val; + __entry->addr = (unsigned long)addr; + __entry->width = width; + ), + + TP_printk("%pS width=%d val=%#llx addr=%#lx", + (void *)__entry->caller, __entry->width, + __entry->val, __entry->addr) +); + +#endif /* _TRACE_RWMMIO_H */ + +#include -- cgit v1.2.3 From cc06af0bbc21bcee40d57e3ee569d3a09741dafd Mon Sep 17 00:00:00 2001 From: Changyuan Lyu Date: Tue, 21 Jun 2022 18:11:25 +0000 Subject: scsi: trace: Print driver_tag and scheduler_tag in SCSI trace Trace events like scsi_dispatch_cmd_start and scsi_dispatch_cmd_done are useful for tracking a command throughout its lifetime. But for some ATA passthrough commands, the information printed in current logs is not enough to identify and match them. For example, if two threads send SMART cmd to the same disk at the same time, their trace logs may look the same, which makes it hard to match scsi_dispatch_cmd_done and scsi_dispatch_cmd_start. Printing tags can help us solve the problem. Further, if a command failed for some reason and then is retried, its driver_tag will change. So scheduler_tag is also included such that we can track the retries of a command. Link: https://lore.kernel.org/r/20220621181125.3211399-1-changyuanl@google.com Reviewed-by: Vishakha Channapattan Reviewed-by: Jolly Shah Reviewed-by: Bart Van Assche Signed-off-by: Changyuan Lyu Signed-off-by: Martin K. Petersen --- include/trace/events/scsi.h | 35 ++++++++++++++++++++++++----------- 1 file changed, 24 insertions(+), 11 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h index 370ade0d4093..a2c7befd451a 100644 --- a/include/trace/events/scsi.h +++ b/include/trace/events/scsi.h @@ -166,6 +166,8 @@ TRACE_EVENT(scsi_dispatch_cmd_start, __field( unsigned int, lun ) __field( unsigned int, opcode ) __field( unsigned int, cmd_len ) + __field( int, driver_tag) + __field( int, scheduler_tag) __field( unsigned int, data_sglen ) __field( unsigned int, prot_sglen ) __field( unsigned char, prot_op ) @@ -179,6 +181,8 @@ TRACE_EVENT(scsi_dispatch_cmd_start, __entry->lun = cmd->device->lun; __entry->opcode = cmd->cmnd[0]; __entry->cmd_len = cmd->cmd_len; + __entry->driver_tag = scsi_cmd_to_rq(cmd)->tag; + __entry->scheduler_tag = scsi_cmd_to_rq(cmd)->internal_tag; __entry->data_sglen = scsi_sg_count(cmd); __entry->prot_sglen = scsi_prot_sg_count(cmd); __entry->prot_op = scsi_get_prot_op(cmd); @@ -186,11 +190,11 @@ TRACE_EVENT(scsi_dispatch_cmd_start, ), TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \ - " prot_op=%s cmnd=(%s %s raw=%s)", + " prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s)", __entry->host_no, __entry->channel, __entry->id, __entry->lun, __entry->data_sglen, __entry->prot_sglen, - show_prot_op_name(__entry->prot_op), - show_opcode_name(__entry->opcode), + show_prot_op_name(__entry->prot_op), __entry->driver_tag, + __entry->scheduler_tag, show_opcode_name(__entry->opcode), __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len), __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len)) ); @@ -209,6 +213,8 @@ TRACE_EVENT(scsi_dispatch_cmd_error, __field( int, rtn ) __field( unsigned int, opcode ) __field( unsigned int, cmd_len ) + __field( int, driver_tag) + __field( int, scheduler_tag) __field( unsigned int, data_sglen ) __field( unsigned int, prot_sglen ) __field( unsigned char, prot_op ) @@ -223,6 +229,8 @@ TRACE_EVENT(scsi_dispatch_cmd_error, __entry->rtn = rtn; __entry->opcode = cmd->cmnd[0]; __entry->cmd_len = cmd->cmd_len; + __entry->driver_tag = scsi_cmd_to_rq(cmd)->tag; + __entry->scheduler_tag = scsi_cmd_to_rq(cmd)->internal_tag; __entry->data_sglen = scsi_sg_count(cmd); __entry->prot_sglen = scsi_prot_sg_count(cmd); __entry->prot_op = scsi_get_prot_op(cmd); @@ -230,11 +238,12 @@ TRACE_EVENT(scsi_dispatch_cmd_error, ), TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \ - " prot_op=%s cmnd=(%s %s raw=%s) rtn=%d", + " prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s)" \ + " rtn=%d", __entry->host_no, __entry->channel, __entry->id, __entry->lun, __entry->data_sglen, __entry->prot_sglen, - show_prot_op_name(__entry->prot_op), - show_opcode_name(__entry->opcode), + show_prot_op_name(__entry->prot_op), __entry->driver_tag, + __entry->scheduler_tag, show_opcode_name(__entry->opcode), __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len), __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len), __entry->rtn) @@ -254,6 +263,8 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template, __field( int, result ) __field( unsigned int, opcode ) __field( unsigned int, cmd_len ) + __field( int, driver_tag) + __field( int, scheduler_tag) __field( unsigned int, data_sglen ) __field( unsigned int, prot_sglen ) __field( unsigned char, prot_op ) @@ -268,19 +279,21 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template, __entry->result = cmd->result; __entry->opcode = cmd->cmnd[0]; __entry->cmd_len = cmd->cmd_len; + __entry->driver_tag = scsi_cmd_to_rq(cmd)->tag; + __entry->scheduler_tag = scsi_cmd_to_rq(cmd)->internal_tag; __entry->data_sglen = scsi_sg_count(cmd); __entry->prot_sglen = scsi_prot_sg_count(cmd); __entry->prot_op = scsi_get_prot_op(cmd); memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len); ), - TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \ - "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \ - "%s host=%s message=%s status=%s)", + TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u " \ + "prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s) " \ + "result=(driver=%s host=%s message=%s status=%s)", __entry->host_no, __entry->channel, __entry->id, __entry->lun, __entry->data_sglen, __entry->prot_sglen, - show_prot_op_name(__entry->prot_op), - show_opcode_name(__entry->opcode), + show_prot_op_name(__entry->prot_op), __entry->driver_tag, + __entry->scheduler_tag, show_opcode_name(__entry->opcode), __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len), __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len), "DRIVER_OK", -- cgit v1.2.3 From 0c4c516fa206d6e8a3986eebd3016a96022792c6 Mon Sep 17 00:00:00 2001 From: Alexander Aring Date: Wed, 22 Jun 2022 14:45:11 -0400 Subject: fs: dlm: remove additional dereference of lksb This patch removes a dereference of lksb of lkb when calling ast tracepoint. First it reduces additional overhead, even if traces are not active. Second we can deference it in TP_fast_assign from the existing lkb parameter. Signed-off-by: Alexander Aring Signed-off-by: David Teigland --- include/trace/events/dlm.h | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/dlm.h b/include/trace/events/dlm.h index 32088c603244..e333176ecfaf 100644 --- a/include/trace/events/dlm.h +++ b/include/trace/events/dlm.h @@ -138,9 +138,9 @@ TRACE_EVENT(dlm_bast, TRACE_EVENT(dlm_ast, - TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, struct dlm_lksb *lksb), + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb), - TP_ARGS(ls, lkb, lksb), + TP_ARGS(ls, lkb), TP_STRUCT__entry( __field(__u32, ls_id) @@ -152,8 +152,8 @@ TRACE_EVENT(dlm_ast, TP_fast_assign( __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; - __entry->sb_flags = lksb->sb_flags; - __entry->sb_status = lksb->sb_status; + __entry->sb_flags = lkb->lkb_lksb->sb_flags; + __entry->sb_status = lkb->lkb_lksb->sb_status; ), TP_printk("ls_id=%u lkb_id=%x sb_flags=%s sb_status=%d", -- cgit v1.2.3 From 5d92a30e900dc97221e36f09ae740457d560d281 Mon Sep 17 00:00:00 2001 From: Alexander Aring Date: Wed, 22 Jun 2022 14:45:12 -0400 Subject: fs: dlm: add resource name to tracepoints This patch adds the resource name to dlm tracepoints. The name usually comes through the lkb_resource, but in some cases a resource may not yet be associated with an lkb, in which case the name and namelen parameters are used. It should be okay to access the lkb_resource and the res_name field at the time when the tracepoint is invoked. The resource is assigned to a lkb and it's reference is being held during the tracepoint call. During this time the resource cannot be freed. Also a lkb will never switch its assigned resource. The name of a dlm_rsb is assigned at creation time and should never be changed during runtime as well. The TP_printk() call uses always a hexadecimal string array representation for the resource name (which is not necessarily ascii.) Signed-off-by: Alexander Aring Signed-off-by: David Teigland --- include/trace/events/dlm.h | 110 +++++++++++++++++++++++++++++++++++++-------- 1 file changed, 92 insertions(+), 18 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/dlm.h b/include/trace/events/dlm.h index e333176ecfaf..bad21222130e 100644 --- a/include/trace/events/dlm.h +++ b/include/trace/events/dlm.h @@ -49,38 +49,52 @@ /* note: we begin tracing dlm_lock_start() only if ls and lkb are found */ TRACE_EVENT(dlm_lock_start, - TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, int mode, - __u32 flags), + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, void *name, + unsigned int namelen, int mode, __u32 flags), - TP_ARGS(ls, lkb, mode, flags), + TP_ARGS(ls, lkb, name, namelen, mode, flags), TP_STRUCT__entry( __field(__u32, ls_id) __field(__u32, lkb_id) __field(int, mode) __field(__u32, flags) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : namelen) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->mode = mode; __entry->flags = flags; + + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); + else if (name) + memcpy(__get_dynamic_array(res_name), name, + __get_dynamic_array_len(res_name)); ), - TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s", + TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s res_name=%s", __entry->ls_id, __entry->lkb_id, show_lock_mode(__entry->mode), - show_lock_flags(__entry->flags)) + show_lock_flags(__entry->flags), + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); TRACE_EVENT(dlm_lock_end, - TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, int mode, __u32 flags, - int error), + TP_PROTO(struct dlm_ls *ls, struct dlm_lkb *lkb, void *name, + unsigned int namelen, int mode, __u32 flags, int error), - TP_ARGS(ls, lkb, mode, flags, error), + TP_ARGS(ls, lkb, name, namelen, mode, flags, error), TP_STRUCT__entry( __field(__u32, ls_id) @@ -88,14 +102,26 @@ TRACE_EVENT(dlm_lock_end, __field(int, mode) __field(__u32, flags) __field(int, error) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : namelen) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->mode = mode; __entry->flags = flags; + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); + else if (name) + memcpy(__get_dynamic_array(res_name), name, + __get_dynamic_array_len(res_name)); + /* return value will be zeroed in those cases by dlm_lock() * we do it here again to not introduce more overhead if * trace isn't running and error reflects the return value. @@ -104,12 +130,15 @@ TRACE_EVENT(dlm_lock_end, __entry->error = 0; else __entry->error = error; + ), - TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s error=%d", + TP_printk("ls_id=%u lkb_id=%x mode=%s flags=%s error=%d res_name=%s", __entry->ls_id, __entry->lkb_id, show_lock_mode(__entry->mode), - show_lock_flags(__entry->flags), __entry->error) + show_lock_flags(__entry->flags), __entry->error, + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); @@ -123,16 +152,28 @@ TRACE_EVENT(dlm_bast, __field(__u32, ls_id) __field(__u32, lkb_id) __field(int, mode) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : 0) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->mode = mode; + + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); ), - TP_printk("ls_id=%u lkb_id=%x mode=%s", __entry->ls_id, - __entry->lkb_id, show_lock_mode(__entry->mode)) + TP_printk("ls_id=%u lkb_id=%x mode=%s res_name=%s", + __entry->ls_id, __entry->lkb_id, + show_lock_mode(__entry->mode), + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); @@ -147,18 +188,29 @@ TRACE_EVENT(dlm_ast, __field(__u32, lkb_id) __field(u8, sb_flags) __field(int, sb_status) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : 0) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->sb_flags = lkb->lkb_lksb->sb_flags; __entry->sb_status = lkb->lkb_lksb->sb_status; + + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); ), - TP_printk("ls_id=%u lkb_id=%x sb_flags=%s sb_status=%d", + TP_printk("ls_id=%u lkb_id=%x sb_flags=%s sb_status=%d res_name=%s", __entry->ls_id, __entry->lkb_id, - show_dlm_sb_flags(__entry->sb_flags), __entry->sb_status) + show_dlm_sb_flags(__entry->sb_flags), __entry->sb_status, + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); @@ -173,17 +225,28 @@ TRACE_EVENT(dlm_unlock_start, __field(__u32, ls_id) __field(__u32, lkb_id) __field(__u32, flags) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : 0) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->flags = flags; + + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); ), - TP_printk("ls_id=%u lkb_id=%x flags=%s", + TP_printk("ls_id=%u lkb_id=%x flags=%s res_name=%s", __entry->ls_id, __entry->lkb_id, - show_lock_flags(__entry->flags)) + show_lock_flags(__entry->flags), + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); @@ -199,18 +262,29 @@ TRACE_EVENT(dlm_unlock_end, __field(__u32, lkb_id) __field(__u32, flags) __field(int, error) + __dynamic_array(unsigned char, res_name, + lkb->lkb_resource ? lkb->lkb_resource->res_length : 0) ), TP_fast_assign( + struct dlm_rsb *r; + __entry->ls_id = ls->ls_global_id; __entry->lkb_id = lkb->lkb_id; __entry->flags = flags; __entry->error = error; + + r = lkb->lkb_resource; + if (r) + memcpy(__get_dynamic_array(res_name), r->res_name, + __get_dynamic_array_len(res_name)); ), - TP_printk("ls_id=%u lkb_id=%x flags=%s error=%d", + TP_printk("ls_id=%u lkb_id=%x flags=%s error=%d res_name=%s", __entry->ls_id, __entry->lkb_id, - show_lock_flags(__entry->flags), __entry->error) + show_lock_flags(__entry->flags), __entry->error, + __print_hex_str(__get_dynamic_array(res_name), + __get_dynamic_array_len(res_name))) ); -- cgit v1.2.3 From 6deb209dc6b0952a460da17ee61223ee3b3429d5 Mon Sep 17 00:00:00 2001 From: Subash Abhinov Kasiviswanathan Date: Fri, 24 Jun 2022 15:34:25 -0600 Subject: net: Print hashed skb addresses for all net and qdisc events The following commits added support for printing the real address- 65875073eddd ("net: use %px to print skb address in trace_netif_receive_skb") 70713dddf3d2 ("net_sched: introduce tracepoint trace_qdisc_enqueue()") 851f36e40962 ("net_sched: use %px to print skb address in trace_qdisc_dequeue()") However, tracing the packet traversal shows a mix of hashes and real addresses. Pasting a sample trace for reference- ping-14249 [002] ..... 3424.046612: netif_rx_entry: dev=lo napi_id=0x3 queue_mapping=0 skbaddr=00000000dcbed83e vlan_tagged=0 vlan_proto=0x0000 vlan_tci=0x0000 protocol=0x0800 ip_summed=0 hash=0x00000000 l4_hash=0 len=84 data_len=0 truesize=768 mac_header_valid=1 mac_header=-14 nr_frags=0 gso_size=0 gso_type=0x0 ping-14249 [002] ..... 3424.046615: netif_rx: dev=lo skbaddr=ffffff888e5d1000 len=84 Switch the trace print formats to %p for all the events to have a consistent format of printing the hashed addresses in all cases. Signed-off-by: Sean Tranchetti Signed-off-by: Subash Abhinov Kasiviswanathan Signed-off-by: David S. Miller --- include/trace/events/net.h | 2 +- include/trace/events/qdisc.h | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/net.h b/include/trace/events/net.h index 032b431b987b..da611a7aaf97 100644 --- a/include/trace/events/net.h +++ b/include/trace/events/net.h @@ -136,7 +136,7 @@ DECLARE_EVENT_CLASS(net_dev_template, __assign_str(name, skb->dev->name); ), - TP_printk("dev=%s skbaddr=%px len=%u", + TP_printk("dev=%s skbaddr=%p len=%u", __get_str(name), __entry->skbaddr, __entry->len) ) diff --git a/include/trace/events/qdisc.h b/include/trace/events/qdisc.h index 59c945b66f9c..a3995925cb05 100644 --- a/include/trace/events/qdisc.h +++ b/include/trace/events/qdisc.h @@ -41,7 +41,7 @@ TRACE_EVENT(qdisc_dequeue, __entry->txq_state = txq->state; ), - TP_printk("dequeue ifindex=%d qdisc handle=0x%X parent=0x%X txq_state=0x%lX packets=%d skbaddr=%px", + TP_printk("dequeue ifindex=%d qdisc handle=0x%X parent=0x%X txq_state=0x%lX packets=%d skbaddr=%p", __entry->ifindex, __entry->handle, __entry->parent, __entry->txq_state, __entry->packets, __entry->skbaddr ) ); @@ -70,7 +70,7 @@ TRACE_EVENT(qdisc_enqueue, __entry->parent = qdisc->parent; ), - TP_printk("enqueue ifindex=%d qdisc handle=0x%X parent=0x%X skbaddr=%px", + TP_printk("enqueue ifindex=%d qdisc handle=0x%X parent=0x%X skbaddr=%p", __entry->ifindex, __entry->handle, __entry->parent, __entry->skbaddr) ); -- cgit v1.2.3 From 286c171b86ebc693e18b485dde3a3fc470af37bd Mon Sep 17 00:00:00 2001 From: Dominique Martinet Date: Mon, 13 Jun 2022 08:32:06 +0900 Subject: 9p fid refcount: add a 9p_fid_ref tracepoint This adds a tracepoint event for 9p fid lifecycle tracing: when a fid is created, its reference count increased/decreased, and freed. The new 9p_fid_ref tracepoint should help anyone wishing to debug any fid problem such as missing clunk (destroy) or use-after-free. Link: https://lkml.kernel.org/r/20220612085330.1451496-6-asmadeus@codewreck.org Signed-off-by: Dominique Martinet --- include/trace/events/9p.h | 48 +++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 48 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/9p.h b/include/trace/events/9p.h index 78c5608a1648..4dfa6d7f83ba 100644 --- a/include/trace/events/9p.h +++ b/include/trace/events/9p.h @@ -77,6 +77,13 @@ EM( P9_TWSTAT, "P9_TWSTAT" ) \ EMe(P9_RWSTAT, "P9_RWSTAT" ) + +#define P9_FID_REFTYPE \ + EM( P9_FID_REF_CREATE, "create " ) \ + EM( P9_FID_REF_GET, "get " ) \ + EM( P9_FID_REF_PUT, "put " ) \ + EMe(P9_FID_REF_DESTROY, "destroy" ) + /* Define EM() to export the enums to userspace via TRACE_DEFINE_ENUM() */ #undef EM #undef EMe @@ -84,6 +91,21 @@ #define EMe(a, b) TRACE_DEFINE_ENUM(a); P9_MSG_T +P9_FID_REFTYPE + +/* And also use EM/EMe to define helper enums -- once */ +#ifndef __9P_DECLARE_TRACE_ENUMS_ONLY_ONCE +#define __9P_DECLARE_TRACE_ENUMS_ONLY_ONCE +#undef EM +#undef EMe +#define EM(a, b) a, +#define EMe(a, b) a + +enum p9_fid_reftype { + P9_FID_REFTYPE +} __mode(byte); + +#endif /* * Now redefine the EM() and EMe() macros to map the enums to the strings @@ -96,6 +118,8 @@ P9_MSG_T #define show_9p_op(type) \ __print_symbolic(type, P9_MSG_T) +#define show_9p_fid_reftype(type) \ + __print_symbolic(type, P9_FID_REFTYPE) TRACE_EVENT(9p_client_req, TP_PROTO(struct p9_client *clnt, int8_t type, int tag), @@ -168,6 +192,30 @@ TRACE_EVENT(9p_protocol_dump, __entry->tag, 0, __entry->line, 16, __entry->line + 16) ); + +TRACE_EVENT(9p_fid_ref, + TP_PROTO(struct p9_fid *fid, __u8 type), + + TP_ARGS(fid, type), + + TP_STRUCT__entry( + __field( int, fid ) + __field( int, refcount ) + __field( __u8, type ) + ), + + TP_fast_assign( + __entry->fid = fid->fid; + __entry->refcount = refcount_read(&fid->count); + __entry->type = type; + ), + + TP_printk("%s fid %d, refcount %d", + show_9p_fid_reftype(__entry->type), + __entry->fid, __entry->refcount) +); + + #endif /* _TRACE_9P_H */ /* This part must be outside protection */ -- cgit v1.2.3 From 2bd0467074f078372ac2c979c56dc94228c90fbf Mon Sep 17 00:00:00 2001 From: Cristian Marussi Date: Thu, 30 Jun 2022 18:31:34 +0100 Subject: include: trace: Add SCMI full message tracing Add a distinct trace event to dump full SCMI message headers and payloads. Link: https://lore.kernel.org/r/20220630173135.2086631-2-cristian.marussi@arm.com Signed-off-by: Cristian Marussi Signed-off-by: Sudeep Holla --- include/trace/events/scmi.h | 31 +++++++++++++++++++++++++++++++ 1 file changed, 31 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/scmi.h b/include/trace/events/scmi.h index cee4b2b64ae4..9108544beca9 100644 --- a/include/trace/events/scmi.h +++ b/include/trace/events/scmi.h @@ -112,6 +112,37 @@ TRACE_EVENT(scmi_rx_done, __entry->transfer_id, __entry->msg_id, __entry->protocol_id, __entry->seq, __entry->msg_type) ); + +TRACE_EVENT(scmi_msg_dump, + TP_PROTO(u8 protocol_id, u8 msg_id, unsigned char *tag, u16 seq, + int status, void *buf, size_t len), + TP_ARGS(protocol_id, msg_id, tag, seq, status, buf, len), + + TP_STRUCT__entry( + __field(u8, protocol_id) + __field(u8, msg_id) + __array(char, tag, 5) + __field(u16, seq) + __field(int, status) + __field(size_t, len) + __dynamic_array(unsigned char, cmd, len) + ), + + TP_fast_assign( + __entry->protocol_id = protocol_id; + __entry->msg_id = msg_id; + strscpy(__entry->tag, tag, 5); + __entry->seq = seq; + __entry->status = status; + __entry->len = len; + memcpy(__get_dynamic_array(cmd), buf, __entry->len); + ), + + TP_printk("pt=%02X t=%s msg_id=%02X seq=%04X s=%d pyld=%s", + __entry->protocol_id, __entry->tag, __entry->msg_id, + __entry->seq, __entry->status, + __print_hex_str(__get_dynamic_array(cmd), __entry->len)) +); #endif /* _TRACE_SCMI_H */ /* This part must be outside protection */ -- cgit v1.2.3 From e699eb9b4f1b98be08197d699e5c34a8b576b26f Mon Sep 17 00:00:00 2001 From: Cristian Marussi Date: Mon, 4 Jul 2022 11:22:39 +0100 Subject: include: trace: Add SCMI fast channel tracing All the currently defined SCMI events are meant to trace only regular SCMI transfers based on SCMI messages exchanges; SCMI transactions based on fast channels, where used, are completely invisible from the tracing point of view. Add support to trace fast channel transactions; while doing that avoid exposing full shared memory location addresses. Link: https://lore.kernel.org/r/20220704102241.2988447-6-cristian.marussi@arm.com Signed-off-by: Cristian Marussi Signed-off-by: Sudeep Holla --- include/trace/events/scmi.h | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/scmi.h b/include/trace/events/scmi.h index 9108544beca9..65016a767b7a 100644 --- a/include/trace/events/scmi.h +++ b/include/trace/events/scmi.h @@ -7,6 +7,31 @@ #include +TRACE_EVENT(scmi_fc_call, + TP_PROTO(u8 protocol_id, u8 msg_id, u32 res_id, u32 val1, u32 val2), + TP_ARGS(protocol_id, msg_id, res_id, val1, val2), + + TP_STRUCT__entry( + __field(u8, protocol_id) + __field(u8, msg_id) + __field(u32, res_id) + __field(u32, val1) + __field(u32, val2) + ), + + TP_fast_assign( + __entry->protocol_id = protocol_id; + __entry->msg_id = msg_id; + __entry->res_id = res_id; + __entry->val1 = val1; + __entry->val2 = val2; + ), + + TP_printk("[0x%02X]:[0x%02X]:[%08X]:%u:%u", + __entry->protocol_id, __entry->msg_id, + __entry->res_id, __entry->val1, __entry->val2) +); + TRACE_EVENT(scmi_xfer_begin, TP_PROTO(int transfer_id, u8 msg_id, u8 protocol_id, u16 seq, bool poll), -- cgit v1.2.3 From b347aa7b57477f71c740e2bbc6d1078a7109ba23 Mon Sep 17 00:00:00 2001 From: Vasily Averin Date: Fri, 3 Jun 2022 06:21:49 +0300 Subject: mm/tracing: add 'accounted' entry into output of allocation tracepoints Slab caches marked with SLAB_ACCOUNT force accounting for every allocation from this cache even if __GFP_ACCOUNT flag is not passed. Unfortunately, at the moment this flag is not visible in ftrace output, and this makes it difficult to analyze the accounted allocations. This patch adds boolean "accounted" entry into trace output, and set it to 'true' for calls used __GFP_ACCOUNT flag and for allocations from caches marked with SLAB_ACCOUNT. Set it to 'false' if accounting is disabled in configs. Signed-off-by: Vasily Averin Acked-by: Shakeel Butt Acked-by: Roman Gushchin Acked-by: Muchun Song Reviewed-by: Hyeonggon Yoo <42.hyeyoo@gmail.com> Link: https://lore.kernel.org/r/c418ed25-65fe-f623-fbf8-1676528859ed@openvz.org Signed-off-by: Vlastimil Babka --- include/trace/events/kmem.h | 40 ++++++++++++++++++++++++++-------------- 1 file changed, 26 insertions(+), 14 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/kmem.h b/include/trace/events/kmem.h index f76668305ac5..4cb51ace600d 100644 --- a/include/trace/events/kmem.h +++ b/include/trace/events/kmem.h @@ -13,11 +13,12 @@ DECLARE_EVENT_CLASS(kmem_alloc, TP_PROTO(unsigned long call_site, const void *ptr, + struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags), + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags), TP_STRUCT__entry( __field( unsigned long, call_site ) @@ -25,6 +26,7 @@ DECLARE_EVENT_CLASS(kmem_alloc, __field( size_t, bytes_req ) __field( size_t, bytes_alloc ) __field( unsigned long, gfp_flags ) + __field( bool, accounted ) ), TP_fast_assign( @@ -33,42 +35,47 @@ DECLARE_EVENT_CLASS(kmem_alloc, __entry->bytes_req = bytes_req; __entry->bytes_alloc = bytes_alloc; __entry->gfp_flags = (__force unsigned long)gfp_flags; + __entry->accounted = IS_ENABLED(CONFIG_MEMCG_KMEM) ? + ((gfp_flags & __GFP_ACCOUNT) || + (s && s->flags & SLAB_ACCOUNT)) : false; ), - TP_printk("call_site=%pS ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s", + TP_printk("call_site=%pS ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s accounted=%s", (void *)__entry->call_site, __entry->ptr, __entry->bytes_req, __entry->bytes_alloc, - show_gfp_flags(__entry->gfp_flags)) + show_gfp_flags(__entry->gfp_flags), + __entry->accounted ? "true" : "false") ); DEFINE_EVENT(kmem_alloc, kmalloc, - TP_PROTO(unsigned long call_site, const void *ptr, + TP_PROTO(unsigned long call_site, const void *ptr, struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags) + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags) ); DEFINE_EVENT(kmem_alloc, kmem_cache_alloc, - TP_PROTO(unsigned long call_site, const void *ptr, + TP_PROTO(unsigned long call_site, const void *ptr, struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags) + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags) ); DECLARE_EVENT_CLASS(kmem_alloc_node, TP_PROTO(unsigned long call_site, const void *ptr, + struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags, int node), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node), + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags, node), TP_STRUCT__entry( __field( unsigned long, call_site ) @@ -77,6 +84,7 @@ DECLARE_EVENT_CLASS(kmem_alloc_node, __field( size_t, bytes_alloc ) __field( unsigned long, gfp_flags ) __field( int, node ) + __field( bool, accounted ) ), TP_fast_assign( @@ -86,33 +94,37 @@ DECLARE_EVENT_CLASS(kmem_alloc_node, __entry->bytes_alloc = bytes_alloc; __entry->gfp_flags = (__force unsigned long)gfp_flags; __entry->node = node; + __entry->accounted = IS_ENABLED(CONFIG_MEMCG_KMEM) ? + ((gfp_flags & __GFP_ACCOUNT) || + (s && s->flags & SLAB_ACCOUNT)) : false; ), - TP_printk("call_site=%pS ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s node=%d", + TP_printk("call_site=%pS ptr=%p bytes_req=%zu bytes_alloc=%zu gfp_flags=%s node=%d accounted=%s", (void *)__entry->call_site, __entry->ptr, __entry->bytes_req, __entry->bytes_alloc, show_gfp_flags(__entry->gfp_flags), - __entry->node) + __entry->node, + __entry->accounted ? "true" : "false") ); DEFINE_EVENT(kmem_alloc_node, kmalloc_node, TP_PROTO(unsigned long call_site, const void *ptr, - size_t bytes_req, size_t bytes_alloc, + struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags, int node), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node) + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags, node) ); DEFINE_EVENT(kmem_alloc_node, kmem_cache_alloc_node, TP_PROTO(unsigned long call_site, const void *ptr, - size_t bytes_req, size_t bytes_alloc, + struct kmem_cache *s, size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags, int node), - TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node) + TP_ARGS(call_site, ptr, s, bytes_req, bytes_alloc, gfp_flags, node) ); TRACE_EVENT(kfree, -- cgit v1.2.3 From 820b8963adaea34a87abbecb906d1f54c0aabfb7 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Wed, 6 Jul 2022 10:50:40 -0400 Subject: net: sock: tracing: Fix sock_exceed_buf_limit not to dereference stale pointer The trace event sock_exceed_buf_limit saves the prot->sysctl_mem pointer and then dereferences it in the TP_printk() portion. This is unsafe as the TP_printk() portion is executed at the time the buffer is read. That is, it can be seconds, minutes, days, months, even years later. If the proto is freed, then this dereference will can also lead to a kernel crash. Instead, save the sysctl_mem array into the ring buffer and have the TP_printk() reference that instead. This is the proper and safe way to read pointers in trace events. Link: https://lore.kernel.org/all/20220706052130.16368-12-kuniyu@amazon.com/ Cc: stable@vger.kernel.org Fixes: 3847ce32aea9f ("core: add tracepoints for queueing skb to rcvbuf") Signed-off-by: Steven Rostedt (Google) Acked-by: Kuniyuki Iwashima Signed-off-by: David S. Miller --- include/trace/events/sock.h | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/sock.h b/include/trace/events/sock.h index 12c315782766..777ee6cbe933 100644 --- a/include/trace/events/sock.h +++ b/include/trace/events/sock.h @@ -98,7 +98,7 @@ TRACE_EVENT(sock_exceed_buf_limit, TP_STRUCT__entry( __array(char, name, 32) - __field(long *, sysctl_mem) + __array(long, sysctl_mem, 3) __field(long, allocated) __field(int, sysctl_rmem) __field(int, rmem_alloc) @@ -110,7 +110,9 @@ TRACE_EVENT(sock_exceed_buf_limit, TP_fast_assign( strncpy(__entry->name, prot->name, 32); - __entry->sysctl_mem = prot->sysctl_mem; + __entry->sysctl_mem[0] = READ_ONCE(prot->sysctl_mem[0]); + __entry->sysctl_mem[1] = READ_ONCE(prot->sysctl_mem[1]); + __entry->sysctl_mem[2] = READ_ONCE(prot->sysctl_mem[2]); __entry->allocated = allocated; __entry->sysctl_rmem = sk_get_rmem0(sk, prot); __entry->rmem_alloc = atomic_read(&sk->sk_rmem_alloc); -- cgit v1.2.3 From 0bb7e14c8e15ad78b7300e7d89a615ea8b8c89a9 Mon Sep 17 00:00:00 2001 From: Li kunyu Date: Wed, 29 Jun 2022 11:00:13 +0800 Subject: blk-iocost: tracing: atomic64_read(&ioc->vtime_rate) is assigned an extra semicolon Remove extra semicolon. Link: https://lkml.kernel.org/r/20220629030013.10362-1-kunyu@nfschina.com Cc: Tejun Heo Cc: Jens Axboe Signed-off-by: Li kunyu Signed-off-by: Steven Rostedt (Google) --- include/trace/events/iocost.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'include/trace/events') diff --git a/include/trace/events/iocost.h b/include/trace/events/iocost.h index e282ce02fa2d..6d1626e7a4ce 100644 --- a/include/trace/events/iocost.h +++ b/include/trace/events/iocost.h @@ -160,7 +160,7 @@ TRACE_EVENT(iocost_ioc_vrate_adj, TP_fast_assign( __assign_str(devname, ioc_name(ioc)); - __entry->old_vrate = atomic64_read(&ioc->vtime_rate);; + __entry->old_vrate = atomic64_read(&ioc->vtime_rate); __entry->new_vrate = new_vrate; __entry->busy_level = ioc->busy_level; __entry->read_missed_ppm = missed_ppm[READ]; -- cgit v1.2.3 From 7649c873c16a384d447f7dbf9b153e333159f914 Mon Sep 17 00:00:00 2001 From: Bart Van Assche Date: Thu, 14 Jul 2022 11:07:18 -0700 Subject: fs/f2fs: Use the enum req_op and blk_opf_t types Improve static type checking by using the enum req_op type for variables that represent a request operation and the new blk_opf_t type for variables that represent request flags. Cc: Jaegeuk Kim Signed-off-by: Bart Van Assche Link: https://lore.kernel.org/r/20220714180729.1065367-53-bvanassche@acm.org Signed-off-by: Jens Axboe --- include/trace/events/f2fs.h | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index 513e889ef8aa..f1e922237736 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -66,7 +66,7 @@ TRACE_DEFINE_ENUM(CP_RESIZE); #define F2FS_OP_FLAGS (REQ_RAHEAD | REQ_SYNC | REQ_META | REQ_PRIO | \ REQ_PREFLUSH | REQ_FUA) -#define F2FS_BIO_FLAG_MASK(t) (t & F2FS_OP_FLAGS) +#define F2FS_BIO_FLAG_MASK(t) (__force u32)((t) & F2FS_OP_FLAGS) #define show_bio_type(op,op_flags) show_bio_op(op), \ show_bio_op_flags(op_flags) @@ -75,12 +75,12 @@ TRACE_DEFINE_ENUM(CP_RESIZE); #define show_bio_op_flags(flags) \ __print_flags(F2FS_BIO_FLAG_MASK(flags), "|", \ - { REQ_RAHEAD, "R" }, \ - { REQ_SYNC, "S" }, \ - { REQ_META, "M" }, \ - { REQ_PRIO, "P" }, \ - { REQ_PREFLUSH, "PF" }, \ - { REQ_FUA, "FUA" }) + { (__force u32)REQ_RAHEAD, "R" }, \ + { (__force u32)REQ_SYNC, "S" }, \ + { (__force u32)REQ_META, "M" }, \ + { (__force u32)REQ_PRIO, "P" }, \ + { (__force u32)REQ_PREFLUSH, "PF" }, \ + { (__force u32)REQ_FUA, "FUA" }) #define show_data_type(type) \ __print_symbolic(type, \ @@ -1036,8 +1036,8 @@ DECLARE_EVENT_CLASS(f2fs__submit_page_bio, __field(pgoff_t, index) __field(block_t, old_blkaddr) __field(block_t, new_blkaddr) - __field(int, op) - __field(int, op_flags) + __field(enum req_op, op) + __field(blk_opf_t, op_flags) __field(int, temp) __field(int, type) ), @@ -1092,8 +1092,8 @@ DECLARE_EVENT_CLASS(f2fs__bio, TP_STRUCT__entry( __field(dev_t, dev) __field(dev_t, target) - __field(int, op) - __field(int, op_flags) + __field(enum req_op, op) + __field(blk_opf_t, op_flags) __field(int, type) __field(sector_t, sector) __field(unsigned int, size) -- cgit v1.2.3 From 6669797b0dd41ced457760b6e1014fdda8ce19ce Mon Sep 17 00:00:00 2001 From: Bart Van Assche Date: Thu, 14 Jul 2022 11:07:22 -0700 Subject: fs/jbd2: Fix the documentation of the jbd2_write_superblock() callers Commit 2a222ca992c3 ("fs: have submit_bh users pass in op and flags separately") renamed the jbd2_write_superblock() 'write_op' argument into 'write_flags'. Propagate this change to the jbd2_write_superblock() callers. Additionally, change the type of 'write_flags' into blk_opf_t. Cc: Mike Christie Cc: Theodore Ts'o Signed-off-by: Bart Van Assche Link: https://lore.kernel.org/r/20220714180729.1065367-57-bvanassche@acm.org Signed-off-by: Jens Axboe --- include/trace/events/jbd2.h | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/jbd2.h b/include/trace/events/jbd2.h index a4dfe005983d..99f783c384bb 100644 --- a/include/trace/events/jbd2.h +++ b/include/trace/events/jbd2.h @@ -355,22 +355,22 @@ TRACE_EVENT(jbd2_update_log_tail, TRACE_EVENT(jbd2_write_superblock, - TP_PROTO(journal_t *journal, int write_op), + TP_PROTO(journal_t *journal, blk_opf_t write_flags), - TP_ARGS(journal, write_op), + TP_ARGS(journal, write_flags), TP_STRUCT__entry( __field( dev_t, dev ) - __field( int, write_op ) + __field( blk_opf_t, write_flags ) ), TP_fast_assign( __entry->dev = journal->j_fs_dev->bd_dev; - __entry->write_op = write_op; + __entry->write_flags = write_flags; ), - TP_printk("dev %d,%d write_op %x", MAJOR(__entry->dev), - MINOR(__entry->dev), __entry->write_op) + TP_printk("dev %d,%d write_flags %x", MAJOR(__entry->dev), + MINOR(__entry->dev), (__force u32)__entry->write_flags) ); TRACE_EVENT(jbd2_lock_buffer_stall, -- cgit v1.2.3 From ed4512590bd5839f8ea9eef1626b0f4db626b1d1 Mon Sep 17 00:00:00 2001 From: Bart Van Assche Date: Thu, 14 Jul 2022 11:07:24 -0700 Subject: fs/nilfs2: Use the enum req_op and blk_opf_t types Improve static type checking by using the enum req_op type for variables that represent a request operation and the new blk_opf_t type for variables that represent request flags. Combine the 'mode' and 'mode_flags' arguments of nilfs_btnode_submit_block into a single argument 'opf'. Reviewed-by: Ryusuke Konishi Signed-off-by: Bart Van Assche Link: https://lore.kernel.org/r/20220714180729.1065367-59-bvanassche@acm.org Signed-off-by: Jens Axboe --- include/trace/events/nilfs2.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/nilfs2.h b/include/trace/events/nilfs2.h index 84ee31fc04cc..8efc6236f57c 100644 --- a/include/trace/events/nilfs2.h +++ b/include/trace/events/nilfs2.h @@ -192,7 +192,7 @@ TRACE_EVENT(nilfs2_mdt_submit_block, TP_PROTO(struct inode *inode, unsigned long ino, unsigned long blkoff, - int mode), + enum req_op mode), TP_ARGS(inode, ino, blkoff, mode), @@ -200,7 +200,7 @@ TRACE_EVENT(nilfs2_mdt_submit_block, __field(struct inode *, inode) __field(unsigned long, ino) __field(unsigned long, blkoff) - __field(int, mode) + __field(enum req_op, mode) ), TP_fast_assign( -- cgit v1.2.3 From 2a04b8d846dca196342862caecadd2a78460d8dc Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 12 Jul 2022 18:58:20 -0400 Subject: tracing: devlink: Use static array for string in devlink_trap_report event The trace event devlink_trap_report uses the __dynamic_array() macro to determine the size of the input_dev_name field. This is because it needs to test the dev field for NULL, and will use "NULL" if it is. But it also has the size of the dynamic array as a fixed IFNAMSIZ bytes. This defeats the purpose of the dynamic array, as this will reserve that amount of bytes on the ring buffer, and to make matters worse, it will even save that size in the event as the event expects it to be dynamic (for which it is not). Since IFNAMSIZ is just 16 bytes, just make it a static array and this will remove the meta data from the event that records the size. Link: https://lkml.kernel.org/r/20220712185820.002d9fb5@gandalf.local.home Cc: Leon Romanovsky Cc: Jiri Pirko Cc: "David S. Miller" Cc: Eric Dumazet Cc: Paolo Abeni Cc: netdev@vger.kernel.org Reviewed-by: Ido Schimmel Tested-by: Ido Schimmel Acked-by: Jakub Kicinski Signed-off-by: Steven Rostedt (Google) --- include/trace/events/devlink.h | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/devlink.h b/include/trace/events/devlink.h index 2814f188d98c..24969184c534 100644 --- a/include/trace/events/devlink.h +++ b/include/trace/events/devlink.h @@ -186,7 +186,7 @@ TRACE_EVENT(devlink_trap_report, __string(driver_name, devlink_to_dev(devlink)->driver->name) __string(trap_name, metadata->trap_name) __string(trap_group_name, metadata->trap_group_name) - __dynamic_array(char, input_dev_name, IFNAMSIZ) + __array(char, input_dev_name, IFNAMSIZ) ), TP_fast_assign( @@ -197,15 +197,14 @@ TRACE_EVENT(devlink_trap_report, __assign_str(driver_name, devlink_to_dev(devlink)->driver->name); __assign_str(trap_name, metadata->trap_name); __assign_str(trap_group_name, metadata->trap_group_name); - __assign_str(input_dev_name, - (input_dev ? input_dev->name : "NULL")); + strscpy(__entry->input_dev_name, input_dev ? input_dev->name : "NULL", IFNAMSIZ); ), TP_printk("bus_name=%s dev_name=%s driver_name=%s trap_name=%s " "trap_group_name=%s input_dev_name=%s", __get_str(bus_name), __get_str(dev_name), __get_str(driver_name), __get_str(trap_name), __get_str(trap_group_name), - __get_str(input_dev_name)) + __entry->input_dev_name) ); #endif /* _TRACE_DEVLINK_H */ -- cgit v1.2.3 From 933ab6d30153f937ffa9471ce64207e6d9acf56e Mon Sep 17 00:00:00 2001 From: Lu Baolu Date: Tue, 12 Jul 2022 08:08:44 +0800 Subject: iommu/vt-d: Move trace/events/intel_iommu.h under iommu This header file is private to the Intel IOMMU driver. Move it to the driver folder. Signed-off-by: Lu Baolu Reviewed-by: Christoph Hellwig Reviewed-by: Jason Gunthorpe Reviewed-by: Steve Wahl Link: https://lore.kernel.org/r/20220514014322.2927339-2-baolu.lu@linux.intel.com Signed-off-by: Joerg Roedel --- include/trace/events/intel_iommu.h | 94 -------------------------------------- 1 file changed, 94 deletions(-) delete mode 100644 include/trace/events/intel_iommu.h (limited to 'include/trace/events') diff --git a/include/trace/events/intel_iommu.h b/include/trace/events/intel_iommu.h deleted file mode 100644 index e5c1ca6d16ee..000000000000 --- a/include/trace/events/intel_iommu.h +++ /dev/null @@ -1,94 +0,0 @@ -/* SPDX-License-Identifier: GPL-2.0 */ -/* - * Intel IOMMU trace support - * - * Copyright (C) 2019 Intel Corporation - * - * Author: Lu Baolu - */ -#undef TRACE_SYSTEM -#define TRACE_SYSTEM intel_iommu - -#if !defined(_TRACE_INTEL_IOMMU_H) || defined(TRACE_HEADER_MULTI_READ) -#define _TRACE_INTEL_IOMMU_H - -#include -#include - -#define MSG_MAX 256 - -TRACE_EVENT(qi_submit, - TP_PROTO(struct intel_iommu *iommu, u64 qw0, u64 qw1, u64 qw2, u64 qw3), - - TP_ARGS(iommu, qw0, qw1, qw2, qw3), - - TP_STRUCT__entry( - __field(u64, qw0) - __field(u64, qw1) - __field(u64, qw2) - __field(u64, qw3) - __string(iommu, iommu->name) - ), - - TP_fast_assign( - __assign_str(iommu, iommu->name); - __entry->qw0 = qw0; - __entry->qw1 = qw1; - __entry->qw2 = qw2; - __entry->qw3 = qw3; - ), - - TP_printk("%s %s: 0x%llx 0x%llx 0x%llx 0x%llx", - __print_symbolic(__entry->qw0 & 0xf, - { QI_CC_TYPE, "cc_inv" }, - { QI_IOTLB_TYPE, "iotlb_inv" }, - { QI_DIOTLB_TYPE, "dev_tlb_inv" }, - { QI_IEC_TYPE, "iec_inv" }, - { QI_IWD_TYPE, "inv_wait" }, - { QI_EIOTLB_TYPE, "p_iotlb_inv" }, - { QI_PC_TYPE, "pc_inv" }, - { QI_DEIOTLB_TYPE, "p_dev_tlb_inv" }, - { QI_PGRP_RESP_TYPE, "page_grp_resp" }), - __get_str(iommu), - __entry->qw0, __entry->qw1, __entry->qw2, __entry->qw3 - ) -); - -TRACE_EVENT(prq_report, - TP_PROTO(struct intel_iommu *iommu, struct device *dev, - u64 dw0, u64 dw1, u64 dw2, u64 dw3, - unsigned long seq), - - TP_ARGS(iommu, dev, dw0, dw1, dw2, dw3, seq), - - TP_STRUCT__entry( - __field(u64, dw0) - __field(u64, dw1) - __field(u64, dw2) - __field(u64, dw3) - __field(unsigned long, seq) - __string(iommu, iommu->name) - __string(dev, dev_name(dev)) - __dynamic_array(char, buff, MSG_MAX) - ), - - TP_fast_assign( - __entry->dw0 = dw0; - __entry->dw1 = dw1; - __entry->dw2 = dw2; - __entry->dw3 = dw3; - __entry->seq = seq; - __assign_str(iommu, iommu->name); - __assign_str(dev, dev_name(dev)); - ), - - TP_printk("%s/%s seq# %ld: %s", - __get_str(iommu), __get_str(dev), __entry->seq, - decode_prq_descriptor(__get_str(buff), MSG_MAX, __entry->dw0, - __entry->dw1, __entry->dw2, __entry->dw3) - ) -); -#endif /* _TRACE_INTEL_IOMMU_H */ - -/* This part must be outside protection */ -#include -- cgit v1.2.3 From fca8300f68fe3fbb2fcda862f0f114011715b3bc Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Mon, 4 Jul 2022 09:14:36 -0400 Subject: tracing/ipv4/ipv6: Use static array for name field in fib*_lookup_table event The fib_lookup_table and fib6_lookup_table events declare name as a dynamic_array, but also give it a fixed size, which defeats the purpose of the dynamic array, especially since the dynamic array also includes meta data in the event to specify its size. Since the size of the name is at most 16 bytes (defined by IFNAMSIZ), it is not worth spending the effort to determine the size of the string. Just use a fixed size array and copy into it. This will save 4 bytes that are used for the meta data that saves the size and position of a dynamic array, and even slightly speed up the event processing. Link: https://lkml.kernel.org/r/20220704091436.3705edbf@rorschach.local.home Cc: David S. Miller Cc: netdev@vger.kernel.org Acked-by: Jakub Kicinski Reviewed-by: David Ahern Signed-off-by: Steven Rostedt (Google) --- include/trace/events/fib.h | 6 +++--- include/trace/events/fib6.h | 8 ++++---- 2 files changed, 7 insertions(+), 7 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/fib.h b/include/trace/events/fib.h index 6f2a4dc35e37..c2300c407f58 100644 --- a/include/trace/events/fib.h +++ b/include/trace/events/fib.h @@ -32,7 +32,7 @@ TRACE_EVENT(fib_table_lookup, __array( __u8, gw6, 16 ) __field( u16, sport ) __field( u16, dport ) - __dynamic_array(char, name, IFNAMSIZ ) + __array(char, name, IFNAMSIZ ) ), TP_fast_assign( @@ -66,7 +66,7 @@ TRACE_EVENT(fib_table_lookup, } dev = nhc ? nhc->nhc_dev : NULL; - __assign_str(name, dev ? dev->name : "-"); + strlcpy(__entry->name, dev ? dev->name : "-", IFNAMSIZ); if (nhc) { if (nhc->nhc_gw_family == AF_INET) { @@ -95,7 +95,7 @@ TRACE_EVENT(fib_table_lookup, __entry->tb_id, __entry->oif, __entry->iif, __entry->proto, __entry->src, __entry->sport, __entry->dst, __entry->dport, __entry->tos, __entry->scope, __entry->flags, - __get_str(name), __entry->gw4, __entry->gw6, __entry->err) + __entry->name, __entry->gw4, __entry->gw6, __entry->err) ); #endif /* _TRACE_FIB_H */ diff --git a/include/trace/events/fib6.h b/include/trace/events/fib6.h index c6abdcc77c12..6e821eb79450 100644 --- a/include/trace/events/fib6.h +++ b/include/trace/events/fib6.h @@ -31,7 +31,7 @@ TRACE_EVENT(fib6_table_lookup, __field( u16, dport ) __field( u8, proto ) __field( u8, rt_type ) - __dynamic_array( char, name, IFNAMSIZ ) + __array( char, name, IFNAMSIZ ) __array( __u8, gw, 16 ) ), @@ -63,9 +63,9 @@ TRACE_EVENT(fib6_table_lookup, } if (res->nh && res->nh->fib_nh_dev) { - __assign_str(name, res->nh->fib_nh_dev); + strlcpy(__entry->name, res->nh->fib_nh_dev->name, IFNAMSIZ); } else { - __assign_str(name, "-"); + strcpy(__entry->name, "-"); } if (res->f6i == net->ipv6.fib6_null_entry) { struct in6_addr in6_zero = {}; @@ -83,7 +83,7 @@ TRACE_EVENT(fib6_table_lookup, __entry->tb_id, __entry->oif, __entry->iif, __entry->proto, __entry->src, __entry->sport, __entry->dst, __entry->dport, __entry->tos, __entry->scope, __entry->flags, - __get_str(name), __entry->gw, __entry->err) + __entry->name, __entry->gw, __entry->err) ); #endif /* _TRACE_FIB6_H */ -- cgit v1.2.3 From 43b2aef3735e0ddb4fc4e6401cd5dc1bf205dead Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 5 Jul 2022 18:37:41 -0400 Subject: neighbor: tracing: Have neigh_create event use __string() The dev field of the neigh_create event uses __dynamic_array() with a fixed size, which defeats the purpose of __dynamic_array(). Looking at the logic, as it already uses __assign_str(), just use the same logic in __string to create the size needed. It appears that because "dev" can be NULL, it needs the check. But __string() can have the same checks as __assign_str() so use them there too. Link: https://lkml.kernel.org/r/20220705183741.35387e3f@rorschach.local.home Cc: David Ahern Cc: David S. Miller Cc: netdev@vger.kernel.org Acked-by: Jakub Kicinski Reviewed-by: David Ahern Signed-off-by: Steven Rostedt (Google) --- include/trace/events/neigh.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'include/trace/events') diff --git a/include/trace/events/neigh.h b/include/trace/events/neigh.h index 62bb17516713..5eaa1fa99171 100644 --- a/include/trace/events/neigh.h +++ b/include/trace/events/neigh.h @@ -30,7 +30,7 @@ TRACE_EVENT(neigh_create, TP_STRUCT__entry( __field(u32, family) - __dynamic_array(char, dev, IFNAMSIZ ) + __string(dev, dev ? dev->name : "NULL") __field(int, entries) __field(u8, created) __field(u8, gc_exempt) -- cgit v1.2.3 From 5409b8053511f9a32ee08c3d16827632a5b17e3f Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 5 Jul 2022 18:45:03 -0400 Subject: scsi: iscsi: tracing: Use the new __vstring() helper Instead of open coding a __dynamic_array() with a fixed length (which defeats the purpose of the dynamic array in the first place). Use the new __vstring() helper that will use a va_list and only write enough of the string into the ring buffer that is needed. Link: https://lkml.kernel.org/r/20220705224750.715763972@goodmis.org Cc: Fred Herard Cc: Ingo Molnar Cc: Andrew Morton Cc: Martin K. Petersen Signed-off-by: Steven Rostedt (Google) --- include/trace/events/iscsi.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/iscsi.h b/include/trace/events/iscsi.h index 87408faf6e4e..8ff2a3ca5d75 100644 --- a/include/trace/events/iscsi.h +++ b/include/trace/events/iscsi.h @@ -26,12 +26,12 @@ DECLARE_EVENT_CLASS(iscsi_log_msg, TP_STRUCT__entry( __string(dname, dev_name(dev) ) - __dynamic_array(char, msg, ISCSI_MSG_MAX ) + __vstring(msg, vaf->fmt, vaf->va) ), TP_fast_assign( __assign_str(dname, dev_name(dev)); - vsnprintf(__get_str(msg), ISCSI_MSG_MAX, vaf->fmt, *vaf->va); + __assign_vstr(msg, vaf->fmt, vaf->va); ), TP_printk("%s: %s",__get_str(dname), __get_str(msg) -- cgit v1.2.3 From 74003fc4ae7619ac5a7bec8748a14f3a8655f3ea Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 5 Jul 2022 18:45:04 -0400 Subject: scsi: qla2xxx: tracing: Use the new __vstring() helper Instead of open coding a __dynamic_array() with a fixed length (which defeats the purpose of the dynamic array in the first place). Use the new __vstring() helper that will use a va_list and only write enough of the string into the ring buffer that is needed. Link: https://lkml.kernel.org/r/20220705224750.896553364@goodmis.org Cc: Bart Van Assche Cc: Ingo Molnar Cc: Andrew Morton Cc: Martin K. Petersen Signed-off-by: Steven Rostedt (Google) --- include/trace/events/qla.h | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/qla.h b/include/trace/events/qla.h index 5857cf682ee7..e7fd55e7dc3d 100644 --- a/include/trace/events/qla.h +++ b/include/trace/events/qla.h @@ -22,11 +22,11 @@ DECLARE_EVENT_CLASS(qla_log_event, TP_STRUCT__entry( __string(buf, buf) - __dynamic_array(char, msg, QLA_MSG_MAX) + __vstring(msg, vaf->fmt, vaf->va) ), TP_fast_assign( __assign_str(buf, buf); - vsnprintf(__get_str(msg), QLA_MSG_MAX, vaf->fmt, *vaf->va); + __assign_vstr(msg, vaf->fmt, vaf->va); ), TP_printk("%s %s", __get_str(buf), __get_str(msg)) -- cgit v1.2.3 From f67939e4b045e1c8e857055463c0b5a88eca4844 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Fri, 22 Jul 2022 15:08:17 -0400 Subject: SUNRPC: Replace dprintk() call site in xs_data_ready Signed-off-by: Chuck Lever Signed-off-by: Trond Myklebust --- include/trace/events/sunrpc.h | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index b61d9c90fa26..21068ad61db8 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -1266,6 +1266,26 @@ TRACE_EVENT(xprt_reserve, ) ); +TRACE_EVENT(xs_data_ready, + TP_PROTO( + const struct rpc_xprt *xprt + ), + + TP_ARGS(xprt), + + TP_STRUCT__entry( + __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) + __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) + ), + + TP_fast_assign( + __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]); + __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]); + ), + + TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port)) +); + TRACE_EVENT(xs_stream_read_data, TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total), -- cgit v1.2.3 From 2af28b241eea816e6f7668d1954f15894b45d7e3 Mon Sep 17 00:00:00 2001 From: David Collins Date: Mon, 27 Jun 2022 16:55:12 -0700 Subject: spmi: trace: fix stack-out-of-bound access in SPMI tracing functions trace_spmi_write_begin() and trace_spmi_read_end() both call memcpy() with a length of "len + 1". This leads to one extra byte being read beyond the end of the specified buffer. Fix this out-of-bound memory access by using a length of "len" instead. Here is a KASAN log showing the issue: BUG: KASAN: stack-out-of-bounds in trace_event_raw_event_spmi_read_end+0x1d0/0x234 Read of size 2 at addr ffffffc0265b7540 by task thermal@2.0-ser/1314 ... Call trace: dump_backtrace+0x0/0x3e8 show_stack+0x2c/0x3c dump_stack_lvl+0xdc/0x11c print_address_description+0x74/0x384 kasan_report+0x188/0x268 kasan_check_range+0x270/0x2b0 memcpy+0x90/0xe8 trace_event_raw_event_spmi_read_end+0x1d0/0x234 spmi_read_cmd+0x294/0x3ac spmi_ext_register_readl+0x84/0x9c regmap_spmi_ext_read+0x144/0x1b0 [regmap_spmi] _regmap_raw_read+0x40c/0x754 regmap_raw_read+0x3a0/0x514 regmap_bulk_read+0x418/0x494 adc5_gen3_poll_wait_hs+0xe8/0x1e0 [qcom_spmi_adc5_gen3] ... __arm64_sys_read+0x4c/0x60 invoke_syscall+0x80/0x218 el0_svc_common+0xec/0x1c8 ... addr ffffffc0265b7540 is located in stack of task thermal@2.0-ser/1314 at offset 32 in frame: adc5_gen3_poll_wait_hs+0x0/0x1e0 [qcom_spmi_adc5_gen3] this frame has 1 object: [32, 33) 'status' Memory state around the buggy address: ffffffc0265b7400: 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1 f1 ffffffc0265b7480: 04 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00 >ffffffc0265b7500: 00 00 00 00 f1 f1 f1 f1 01 f3 f3 f3 00 00 00 00 ^ ffffffc0265b7580: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ffffffc0265b7600: f1 f1 f1 f1 01 f2 07 f2 f2 f2 01 f3 00 00 00 00 ================================================================== Fixes: a9fce374815d ("spmi: add command tracepoints for SPMI") Cc: stable@vger.kernel.org Reviewed-by: Stephen Boyd Acked-by: Steven Rostedt (Google) Signed-off-by: David Collins Link: https://lore.kernel.org/r/20220627235512.2272783-1-quic_collinsd@quicinc.com Signed-off-by: Greg Kroah-Hartman --- include/trace/events/spmi.h | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/spmi.h b/include/trace/events/spmi.h index 8b60efe18ba6..a6819fd85cdf 100644 --- a/include/trace/events/spmi.h +++ b/include/trace/events/spmi.h @@ -21,15 +21,15 @@ TRACE_EVENT(spmi_write_begin, __field ( u8, sid ) __field ( u16, addr ) __field ( u8, len ) - __dynamic_array ( u8, buf, len + 1 ) + __dynamic_array ( u8, buf, len ) ), TP_fast_assign( __entry->opcode = opcode; __entry->sid = sid; __entry->addr = addr; - __entry->len = len + 1; - memcpy(__get_dynamic_array(buf), buf, len + 1); + __entry->len = len; + memcpy(__get_dynamic_array(buf), buf, len); ), TP_printk("opc=%d sid=%02d addr=0x%04x len=%d buf=0x[%*phD]", @@ -92,7 +92,7 @@ TRACE_EVENT(spmi_read_end, __field ( u16, addr ) __field ( int, ret ) __field ( u8, len ) - __dynamic_array ( u8, buf, len + 1 ) + __dynamic_array ( u8, buf, len ) ), TP_fast_assign( @@ -100,8 +100,8 @@ TRACE_EVENT(spmi_read_end, __entry->sid = sid; __entry->addr = addr; __entry->ret = ret; - __entry->len = len + 1; - memcpy(__get_dynamic_array(buf), buf, len + 1); + __entry->len = len; + memcpy(__get_dynamic_array(buf), buf, len); ), TP_printk("opc=%d sid=%02d addr=0x%04x ret=%d len=%02d buf=0x[%*phD]", -- cgit v1.2.3 From 48863ffd3e81b6ec98606d3479c50aa77b7a98a9 Mon Sep 17 00:00:00 2001 From: Pavel Begunkov Date: Thu, 16 Jun 2022 13:57:20 +0100 Subject: io_uring: clean up tracing events We have lots of trace events accepting an io_uring request and wanting to print some of its fields like user_data, opcode, flags and so on. However, as trace points were unaware of io_uring structures, we had to pass all the fields as arguments. Teach trace/events/io_uring.h about struct io_kiocb and stop the misery of passing a horde of arguments to trace helpers. Signed-off-by: Pavel Begunkov Link: https://lore.kernel.org/r/40ff72f92798114e56d400f2b003beb6cde6ef53.1655384063.git.asml.silence@gmail.com Signed-off-by: Jens Axboe --- include/trace/events/io_uring.h | 142 ++++++++++++++++------------------------ 1 file changed, 57 insertions(+), 85 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h index aa2f951b07cd..3bc8dec9acaa 100644 --- a/include/trace/events/io_uring.h +++ b/include/trace/events/io_uring.h @@ -7,6 +7,7 @@ #include #include +#include #include struct io_wq_work; @@ -97,9 +98,7 @@ TRACE_EVENT(io_uring_register, /** * io_uring_file_get - called before getting references to an SQE file * - * @ctx: pointer to a ring context structure * @req: pointer to a submitted request - * @user_data: user data associated with the request * @fd: SQE file descriptor * * Allows to trace out how often an SQE file reference is obtained, which can @@ -108,9 +107,9 @@ TRACE_EVENT(io_uring_register, */ TRACE_EVENT(io_uring_file_get, - TP_PROTO(void *ctx, void *req, unsigned long long user_data, int fd), + TP_PROTO(struct io_kiocb *req, int fd), - TP_ARGS(ctx, req, user_data, fd), + TP_ARGS(req, fd), TP_STRUCT__entry ( __field( void *, ctx ) @@ -120,9 +119,9 @@ TRACE_EVENT(io_uring_file_get, ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; + __entry->user_data = req->cqe.user_data; __entry->fd = fd; ), @@ -133,22 +132,16 @@ TRACE_EVENT(io_uring_file_get, /** * io_uring_queue_async_work - called before submitting a new async work * - * @ctx: pointer to a ring context structure * @req: pointer to a submitted request - * @user_data: user data associated with the request - * @opcode: opcode of request - * @flags request flags - * @work: pointer to a submitted io_wq_work * @rw: type of workqueue, hashed or normal * * Allows to trace asynchronous work submission. */ TRACE_EVENT(io_uring_queue_async_work, - TP_PROTO(void *ctx, void * req, unsigned long long user_data, u8 opcode, - unsigned int flags, struct io_wq_work *work, int rw), + TP_PROTO(struct io_kiocb *req, int rw), - TP_ARGS(ctx, req, user_data, opcode, flags, work, rw), + TP_ARGS(req, rw), TP_STRUCT__entry ( __field( void *, ctx ) @@ -159,19 +152,19 @@ TRACE_EVENT(io_uring_queue_async_work, __field( struct io_wq_work *, work ) __field( int, rw ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; - __entry->flags = flags; - __entry->opcode = opcode; - __entry->work = work; + __entry->user_data = req->cqe.user_data; + __entry->flags = req->flags; + __entry->opcode = req->opcode; + __entry->work = &req->work; __entry->rw = rw; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, request %p, user_data 0x%llx, opcode %s, flags 0x%x, %s queue, work %p", @@ -183,19 +176,16 @@ TRACE_EVENT(io_uring_queue_async_work, /** * io_uring_defer - called when an io_uring request is deferred * - * @ctx: pointer to a ring context structure * @req: pointer to a deferred request - * @user_data: user data associated with the request - * @opcode: opcode of request * * Allows to track deferred requests, to get an insight about what requests are * not started immediately. */ TRACE_EVENT(io_uring_defer, - TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode), + TP_PROTO(struct io_kiocb *req), - TP_ARGS(ctx, req, user_data, opcode), + TP_ARGS(req), TP_STRUCT__entry ( __field( void *, ctx ) @@ -203,16 +193,16 @@ TRACE_EVENT(io_uring_defer, __field( unsigned long long, data ) __field( u8, opcode ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->data = user_data; - __entry->opcode = opcode; + __entry->data = req->cqe.user_data; + __entry->opcode = req->opcode; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, request %p, user_data 0x%llx, opcode %s", @@ -224,7 +214,6 @@ TRACE_EVENT(io_uring_defer, * io_uring_link - called before the io_uring request added into link_list of * another request * - * @ctx: pointer to a ring context structure * @req: pointer to a linked request * @target_req: pointer to a previous request, that would contain @req * @@ -233,9 +222,9 @@ TRACE_EVENT(io_uring_defer, */ TRACE_EVENT(io_uring_link, - TP_PROTO(void *ctx, void *req, void *target_req), + TP_PROTO(struct io_kiocb *req, struct io_kiocb *target_req), - TP_ARGS(ctx, req, target_req), + TP_ARGS(req, target_req), TP_STRUCT__entry ( __field( void *, ctx ) @@ -244,7 +233,7 @@ TRACE_EVENT(io_uring_link, ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; __entry->target_req = target_req; ), @@ -285,10 +274,7 @@ TRACE_EVENT(io_uring_cqring_wait, /** * io_uring_fail_link - called before failing a linked request * - * @ctx: pointer to a ring context structure * @req: request, which links were cancelled - * @user_data: user data associated with the request - * @opcode: opcode of request * @link: cancelled link * * Allows to track linked requests cancellation, to see not only that some work @@ -296,9 +282,9 @@ TRACE_EVENT(io_uring_cqring_wait, */ TRACE_EVENT(io_uring_fail_link, - TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, void *link), + TP_PROTO(struct io_kiocb *req, struct io_kiocb *link), - TP_ARGS(ctx, req, user_data, opcode, link), + TP_ARGS(req, link), TP_STRUCT__entry ( __field( void *, ctx ) @@ -307,17 +293,17 @@ TRACE_EVENT(io_uring_fail_link, __field( u8, opcode ) __field( void *, link ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; - __entry->opcode = opcode; + __entry->user_data = req->cqe.user_data; + __entry->opcode = req->opcode; __entry->link = link; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, request %p, user_data 0x%llx, opcode %s, link %p", @@ -376,23 +362,17 @@ TRACE_EVENT(io_uring_complete, /** * io_uring_submit_sqe - called before submitting one SQE * - * @ctx: pointer to a ring context structure * @req: pointer to a submitted request - * @user_data: user data associated with the request - * @opcode: opcode of request - * @flags request flags * @force_nonblock: whether a context blocking or not - * @sq_thread: true if sq_thread has submitted this SQE * * Allows to track SQE submitting, to understand what was the source of it, SQ * thread or io_uring_enter call. */ TRACE_EVENT(io_uring_submit_sqe, - TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, u32 flags, - bool force_nonblock, bool sq_thread), + TP_PROTO(struct io_kiocb *req, bool force_nonblock), - TP_ARGS(ctx, req, user_data, opcode, flags, force_nonblock, sq_thread), + TP_ARGS(req, force_nonblock), TP_STRUCT__entry ( __field( void *, ctx ) @@ -403,19 +383,19 @@ TRACE_EVENT(io_uring_submit_sqe, __field( bool, force_nonblock ) __field( bool, sq_thread ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; - __entry->opcode = opcode; - __entry->flags = flags; + __entry->user_data = req->cqe.user_data; + __entry->opcode = req->opcode; + __entry->flags = req->flags; __entry->force_nonblock = force_nonblock; - __entry->sq_thread = sq_thread; + __entry->sq_thread = req->ctx->flags & IORING_SETUP_SQPOLL; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, req %p, user_data 0x%llx, opcode %s, flags 0x%x, " @@ -427,10 +407,7 @@ TRACE_EVENT(io_uring_submit_sqe, /* * io_uring_poll_arm - called after arming a poll wait if successful * - * @ctx: pointer to a ring context structure * @req: pointer to the armed request - * @user_data: user data associated with the request - * @opcode: opcode of request * @mask: request poll events mask * @events: registered events of interest * @@ -439,10 +416,9 @@ TRACE_EVENT(io_uring_submit_sqe, */ TRACE_EVENT(io_uring_poll_arm, - TP_PROTO(void *ctx, void *req, u64 user_data, u8 opcode, - int mask, int events), + TP_PROTO(struct io_kiocb *req, int mask, int events), - TP_ARGS(ctx, req, user_data, opcode, mask, events), + TP_ARGS(req, mask, events), TP_STRUCT__entry ( __field( void *, ctx ) @@ -452,18 +428,18 @@ TRACE_EVENT(io_uring_poll_arm, __field( int, mask ) __field( int, events ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; - __entry->opcode = opcode; + __entry->user_data = req->cqe.user_data; + __entry->opcode = req->opcode; __entry->mask = mask; __entry->events = events; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, req %p, user_data 0x%llx, opcode %s, mask 0x%x, events 0x%x", @@ -475,18 +451,15 @@ TRACE_EVENT(io_uring_poll_arm, /* * io_uring_task_add - called after adding a task * - * @ctx: pointer to a ring context structure * @req: pointer to request - * @user_data: user data associated with the request - * @opcode: opcode of request * @mask: request poll events mask * */ TRACE_EVENT(io_uring_task_add, - TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, int mask), + TP_PROTO(struct io_kiocb *req, int mask), - TP_ARGS(ctx, req, user_data, opcode, mask), + TP_ARGS(req, mask), TP_STRUCT__entry ( __field( void *, ctx ) @@ -495,17 +468,17 @@ TRACE_EVENT(io_uring_task_add, __field( u8, opcode ) __field( int, mask ) - __string( op_str, io_uring_get_opcode(opcode) ) + __string( op_str, io_uring_get_opcode(req->opcode) ) ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; - __entry->user_data = user_data; - __entry->opcode = opcode; + __entry->user_data = req->cqe.user_data; + __entry->opcode = req->opcode; __entry->mask = mask; - __assign_str(op_str, io_uring_get_opcode(opcode)); + __assign_str(op_str, io_uring_get_opcode(req->opcode)); ), TP_printk("ring %p, req %p, user_data 0x%llx, opcode %s, mask %x", @@ -518,7 +491,6 @@ TRACE_EVENT(io_uring_task_add, * io_uring_req_failed - called when an sqe is errored dring submission * * @sqe: pointer to the io_uring_sqe that failed - * @ctx: pointer to a ring context structure * @req: pointer to request * @error: error it failed with * @@ -526,9 +498,9 @@ TRACE_EVENT(io_uring_task_add, */ TRACE_EVENT(io_uring_req_failed, - TP_PROTO(const struct io_uring_sqe *sqe, void *ctx, void *req, int error), + TP_PROTO(const struct io_uring_sqe *sqe, struct io_kiocb *req, int error), - TP_ARGS(sqe, ctx, req, error), + TP_ARGS(sqe, req, error), TP_STRUCT__entry ( __field( void *, ctx ) @@ -552,7 +524,7 @@ TRACE_EVENT(io_uring_req_failed, ), TP_fast_assign( - __entry->ctx = ctx; + __entry->ctx = req->ctx; __entry->req = req; __entry->user_data = sqe->user_data; __entry->opcode = sqe->opcode; -- cgit v1.2.3 From eccd8801858f03a19a4d1f8fef27e3d6e17b21fd Mon Sep 17 00:00:00 2001 From: Dylan Yudaken Date: Wed, 22 Jun 2022 06:40:27 -0700 Subject: io_uring: add trace event for running task work This is useful for investigating if task_work is batching Signed-off-by: Dylan Yudaken Link: https://lore.kernel.org/r/20220622134028.2013417-8-dylany@fb.com Signed-off-by: Jens Axboe --- include/trace/events/io_uring.h | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h index 3bc8dec9acaa..918e3a43e4b2 100644 --- a/include/trace/events/io_uring.h +++ b/include/trace/events/io_uring.h @@ -600,6 +600,36 @@ TRACE_EVENT(io_uring_cqe_overflow, __entry->cflags, __entry->ocqe) ); +/* + * io_uring_task_work_run - ran task work + * + * @tctx: pointer to a io_uring_task + * @count: how many functions it ran + * @loops: how many loops it ran + * + */ +TRACE_EVENT(io_uring_task_work_run, + + TP_PROTO(void *tctx, unsigned int count, unsigned int loops), + + TP_ARGS(tctx, count, loops), + + TP_STRUCT__entry ( + __field( void *, tctx ) + __field( unsigned int, count ) + __field( unsigned int, loops ) + ), + + TP_fast_assign( + __entry->tctx = tctx; + __entry->count = count; + __entry->loops = loops; + ), + + TP_printk("tctx %p, count %u, loops %u", + __entry->tctx, __entry->count, __entry->loops) +); + #endif /* _TRACE_IO_URING_H */ /* This part must be outside protection */ -- cgit v1.2.3 From 9b26e811e934eebda59362c9a03d082852552574 Mon Sep 17 00:00:00 2001 From: Dylan Yudaken Date: Thu, 30 Jun 2022 02:12:30 -0700 Subject: io_uring: fix io_uring_cqe_overflow trace format Make the trace format consistent with io_uring_complete for cflags Signed-off-by: Dylan Yudaken Link: https://lore.kernel.org/r/20220630091231.1456789-12-dylany@fb.com Signed-off-by: Jens Axboe --- include/trace/events/io_uring.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'include/trace/events') diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h index 918e3a43e4b2..95a8cfaad15a 100644 --- a/include/trace/events/io_uring.h +++ b/include/trace/events/io_uring.h @@ -594,7 +594,7 @@ TRACE_EVENT(io_uring_cqe_overflow, __entry->ocqe = ocqe; ), - TP_printk("ring %p, user_data 0x%llx, res %d, flags %x, " + TP_printk("ring %p, user_data 0x%llx, res %d, cflags 0x%x, " "overflow_cqe %p", __entry->ctx, __entry->user_data, __entry->res, __entry->cflags, __entry->ocqe) -- cgit v1.2.3 From 1c849b481b3e4f8c36f297cd3aa88ef52a19cee9 Mon Sep 17 00:00:00 2001 From: Stefan Roesch Date: Thu, 16 Jun 2022 14:22:19 -0700 Subject: io_uring: Add tracepoint for short writes This adds the io_uring_short_write tracepoint to io_uring. A short write is issued if not all pages that are required for a write are in the page cache and the async buffered writes have to return EAGAIN. Signed-off-by: Stefan Roesch Link: https://lore.kernel.org/r/20220616212221.2024518-13-shr@fb.com Signed-off-by: Jens Axboe --- include/trace/events/io_uring.h | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h index 95a8cfaad15a..c5b21ff0ac85 100644 --- a/include/trace/events/io_uring.h +++ b/include/trace/events/io_uring.h @@ -630,6 +630,31 @@ TRACE_EVENT(io_uring_task_work_run, __entry->tctx, __entry->count, __entry->loops) ); +TRACE_EVENT(io_uring_short_write, + + TP_PROTO(void *ctx, u64 fpos, u64 wanted, u64 got), + + TP_ARGS(ctx, fpos, wanted, got), + + TP_STRUCT__entry( + __field(void *, ctx) + __field(u64, fpos) + __field(u64, wanted) + __field(u64, got) + ), + + TP_fast_assign( + __entry->ctx = ctx; + __entry->fpos = fpos; + __entry->wanted = wanted; + __entry->got = got; + ), + + TP_printk("ring %p, fpos %lld, wanted %lld, got %lld", + __entry->ctx, __entry->fpos, + __entry->wanted, __entry->got) +); + #endif /* _TRACE_IO_URING_H */ /* This part must be outside protection */ -- cgit v1.2.3 From b8bea09a456fc31af8f10029e69d105cac7e530e Mon Sep 17 00:00:00 2001 From: Qu Wenruo Date: Wed, 1 Jun 2022 17:46:59 +0800 Subject: btrfs: add trace event for submitted RAID56 bio Add tracepoint for better insight to how the RAID56 data are submitted. The output looks like this: (trace event header and UUID skipped) raid56_read_partial: full_stripe=389152768 devid=3 type=DATA1 offset=32768 opf=0x0 physical=323059712 len=32768 raid56_read_partial: full_stripe=389152768 devid=1 type=DATA2 offset=0 opf=0x0 physical=67174400 len=65536 raid56_write_stripe: full_stripe=389152768 devid=3 type=DATA1 offset=0 opf=0x1 physical=323026944 len=32768 raid56_write_stripe: full_stripe=389152768 devid=2 type=PQ1 offset=0 opf=0x1 physical=323026944 len=32768 The above debug output is from a 32K data write into an empty RAID56 data chunk. Some explanation on the event output: full_stripe: the logical bytenr of the full stripe devid: btrfs devid type: raid stripe type. DATA1: the first data stripe DATA2: the second data stripe PQ1: the P stripe PQ2: the Q stripe offset: the offset inside the stripe. opf: the bio op type physical: the physical offset the bio is for len: the length of the bio The first two lines are from partial RMW read, which is reading the remaining data stripes from disks. The last two lines are for full stripe RMW write, which is writing the involved two 16K stripes (one for DATA1 stripe, one for P stripe). The stripe for DATA2 doesn't need to be written. There are 5 types of trace events: - raid56_read_partial Read remaining data for regular read/write path. - raid56_write_stripe Write the modified stripes for regular read/write path. - raid56_scrub_read_recover Read remaining data for scrub recovery path. - raid56_scrub_write_stripe Write the modified stripes for scrub path. - raid56_scrub_read Read remaining data for scrub path. Also, since the trace events are included at super.c, we have to export needed structure definitions to 'raid56.h' and include the header in super.c, or we're unable to access those members. Signed-off-by: Qu Wenruo Reviewed-by: David Sterba [ reformat comments ] Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 94 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 94 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 9ae94ef3e270..29fa8ea2cc0f 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -30,6 +30,8 @@ struct btrfs_qgroup; struct extent_io_tree; struct prelim_ref; struct btrfs_space_info; +struct btrfs_raid_bio; +struct raid56_bio_trace_info; #define show_ref_type(type) \ __print_symbolic(type, \ @@ -2258,6 +2260,98 @@ DEFINE_EVENT(btrfs__space_info_update, update_bytes_pinned, TP_ARGS(fs_info, sinfo, old, diff) ); +DECLARE_EVENT_CLASS(btrfs_raid56_bio, + + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info), + + TP_STRUCT__entry_btrfs( + __field( u64, full_stripe ) + __field( u64, physical ) + __field( u64, devid ) + __field( u32, offset ) + __field( u32, len ) + __field( u8, opf ) + __field( u8, total_stripes ) + __field( u8, real_stripes ) + __field( u8, nr_data ) + __field( u8, stripe_nr ) + ), + + TP_fast_assign_btrfs(rbio->bioc->fs_info, + __entry->full_stripe = rbio->bioc->raid_map[0]; + __entry->physical = bio->bi_iter.bi_sector << SECTOR_SHIFT; + __entry->len = bio->bi_iter.bi_size; + __entry->opf = bio_op(bio); + __entry->devid = trace_info->devid; + __entry->offset = trace_info->offset; + __entry->stripe_nr = trace_info->stripe_nr; + __entry->total_stripes = rbio->bioc->num_stripes; + __entry->real_stripes = rbio->real_stripes; + __entry->nr_data = rbio->nr_data; + ), + /* + * For type output, we need to output things like "DATA1" + * (the first data stripe), "DATA2" (the second data stripe), + * "PQ1" (P stripe),"PQ2" (Q stripe), "REPLACE0" (replace target device). + */ + TP_printk_btrfs( +"full_stripe=%llu devid=%lld type=%s%d offset=%d opf=0x%x physical=%llu len=%u", + __entry->full_stripe, __entry->devid, + (__entry->stripe_nr < __entry->nr_data) ? "DATA" : + ((__entry->stripe_nr < __entry->real_stripes) ? "PQ" : + "REPLACE"), + (__entry->stripe_nr < __entry->nr_data) ? + (__entry->stripe_nr + 1) : + ((__entry->stripe_nr < __entry->real_stripes) ? + (__entry->stripe_nr - __entry->nr_data + 1) : 0), + __entry->offset, __entry->opf, __entry->physical, __entry->len) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_read_partial, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_write_stripe, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_write_stripe, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_read, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + +DEFINE_EVENT(btrfs_raid56_bio, raid56_scrub_read_recover, + TP_PROTO(const struct btrfs_raid_bio *rbio, + const struct bio *bio, + const struct raid56_bio_trace_info *trace_info), + + TP_ARGS(rbio, bio, trace_info) +); + #endif /* _TRACE_BTRFS_H */ /* This part must be outside protection */ -- cgit v1.2.3 From 5bea2508811ec76105b01c90c1f1661024c257a9 Mon Sep 17 00:00:00 2001 From: Johannes Thumshirn Date: Thu, 9 Jun 2022 09:28:04 -0700 Subject: btrfs: add tracepoints for ordered extents When debugging a reference counting issue with ordered extents, I've found we're lacking a lot of tracepoint coverage in the ordered extent code. Close these gaps by adding tracepoints after every refcount_inc() in the ordered extent code. Reviewed-by: Boris Burkov Reviewed-by: Qu Wenruo Reviewed-by: Anand Jain Signed-off-by: Johannes Thumshirn Reviewed-by: David Sterba Signed-off-by: David Sterba --- include/trace/events/btrfs.h | 64 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 64 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h index 29fa8ea2cc0f..73df80d462dc 100644 --- a/include/trace/events/btrfs.h +++ b/include/trace/events/btrfs.h @@ -598,6 +598,70 @@ DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_put, TP_ARGS(inode, ordered) ); +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_range, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_first_range, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_for_logging, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_lookup_first, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_split, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_dec_test_pending, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + +DEFINE_EVENT(btrfs__ordered_extent, btrfs_ordered_extent_mark_finished, + + TP_PROTO(const struct btrfs_inode *inode, + const struct btrfs_ordered_extent *ordered), + + TP_ARGS(inode, ordered) +); + DECLARE_EVENT_CLASS(btrfs__writepage, TP_PROTO(const struct page *page, const struct inode *inode, -- cgit v1.2.3 From 3f7ced7ac9af43fbc0b886aa9ef4397a5fa4b6e1 Mon Sep 17 00:00:00 2001 From: Lukasz Luba Date: Mon, 13 Jun 2022 13:43:25 +0100 Subject: drivers/thermal/cpufreq_cooling : Refactor thermal_power_cpu_get_power tracing Simplify the thermal_power_cpu_get_power trace event by removing complicated cpumask and variable length array. Now the tools parsing trace output don't have to hassle to get this power data. The simplified format version uses 'policy->cpu'. Remove also the 'load' information completely since there is very little value of it in this trace event. To get the CPUs' load (or utilization) there are other dedicated trace hooks in the kernel. This patch also simplifies and speeds-up the main cooling code when that trace event is enabled. Rename the trace event to avoid confusion of tools which parse the trace file. Acked-by: Viresh Kumar Signed-off-by: Lukasz Luba Link: https://lore.kernel.org/r/20220613124327.30766-3-lukasz.luba@arm.com Signed-off-by: Daniel Lezcano --- include/trace/events/thermal.h | 28 ++++++++-------------------- 1 file changed, 8 insertions(+), 20 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/thermal.h b/include/trace/events/thermal.h index 8a5f04888abd..e58bf3072f32 100644 --- a/include/trace/events/thermal.h +++ b/include/trace/events/thermal.h @@ -92,34 +92,22 @@ TRACE_EVENT(thermal_zone_trip, ); #ifdef CONFIG_CPU_THERMAL -TRACE_EVENT(thermal_power_cpu_get_power, - TP_PROTO(const struct cpumask *cpus, unsigned long freq, u32 *load, - size_t load_len, u32 dynamic_power), +TRACE_EVENT(thermal_power_cpu_get_power_simple, + TP_PROTO(int cpu, u32 power), - TP_ARGS(cpus, freq, load, load_len, dynamic_power), + TP_ARGS(cpu, power), TP_STRUCT__entry( - __bitmask(cpumask, num_possible_cpus()) - __field(unsigned long, freq ) - __dynamic_array(u32, load, load_len) - __field(size_t, load_len ) - __field(u32, dynamic_power ) + __field(int, cpu) + __field(u32, power) ), TP_fast_assign( - __assign_bitmask(cpumask, cpumask_bits(cpus), - num_possible_cpus()); - __entry->freq = freq; - memcpy(__get_dynamic_array(load), load, - load_len * sizeof(*load)); - __entry->load_len = load_len; - __entry->dynamic_power = dynamic_power; + __entry->cpu = cpu; + __entry->power = power; ), - TP_printk("cpus=%s freq=%lu load={%s} dynamic_power=%d", - __get_bitmask(cpumask), __entry->freq, - __print_array(__get_dynamic_array(load), __entry->load_len, 4), - __entry->dynamic_power) + TP_printk("cpu=%d power=%u", __entry->cpu, __entry->power) ); TRACE_EVENT(thermal_power_cpu_limit, -- cgit v1.2.3 From 28fffa6c57906ffa07e84f12aae5d99993cafdae Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Tue, 21 Jun 2022 10:06:16 -0400 Subject: SUNRPC: Expand the svc_alloc_arg_err tracepoint Record not only the number of pages requested, but the number of pages that were actually allocated, to get a measure of progress (or lack thereof). Signed-off-by: Chuck Lever --- include/trace/events/sunrpc.h | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index b61d9c90fa26..5c48be033cc7 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -1989,20 +1989,24 @@ TRACE_EVENT(svc_wake_up, TRACE_EVENT(svc_alloc_arg_err, TP_PROTO( - unsigned int pages + unsigned int requested, + unsigned int allocated ), - TP_ARGS(pages), + TP_ARGS(requested, allocated), TP_STRUCT__entry( - __field(unsigned int, pages) + __field(unsigned int, requested) + __field(unsigned int, allocated) ), TP_fast_assign( - __entry->pages = pages; + __entry->requested = requested; + __entry->allocated = allocated; ), - TP_printk("pages=%u", __entry->pages) + TP_printk("requested=%u allocated=%u", + __entry->requested, __entry->allocated) ); DECLARE_EVENT_CLASS(svc_deferred_event, -- cgit v1.2.3 From 792575348ff70e05c6040d02fce38e949ef92c37 Mon Sep 17 00:00:00 2001 From: Daniel Bristot de Oliveira Date: Fri, 29 Jul 2022 11:38:43 +0200 Subject: rv/include: Add deterministic automata monitor definition via C macros In Linux terms, the runtime verification monitors are encapsulated inside the "RV monitor" abstraction. The "RV monitor" includes a set of instances of the monitor (per-cpu monitor, per-task monitor, and so on), the helper functions that glue the monitor to the system reference model, and the trace output as a reaction for event parsing and exceptions, as depicted below: Linux +----- RV Monitor ----------------------------------+ Formal Realm | | Realm +-------------------+ +----------------+ +-----------------+ | Linux kernel | | Monitor | | Reference | | Tracing | -> | Instance(s) | <- | Model | | (instrumentation) | | (verification) | | (specification) | +-------------------+ +----------------+ +-----------------+ | | | | V | | +----------+ | | | Reaction | | | +--+--+--+-+ | | | | | | | | | +-> trace output ? | +------------------------|--|----------------------+ | +----> panic ? +-------> Add the rv/da_monitor.h, enabling automatic code generation for the *Monitor Instance(s)* using C macros, and code to support it. The benefits of the usage of macro for monitor synthesis are 3-fold as it: - Reduces the code duplication; - Facilitates the bug fix/improvement; - Avoids the case of developers changing the core of the monitor code to manipulate the model in a (let's say) non-standard way. This initial implementation presents three different types of monitor instances: - DECLARE_DA_MON_GLOBAL(name, type) - DECLARE_DA_MON_PER_CPU(name, type) - DECLARE_DA_MON_PER_TASK(name, type) The first declares the functions for a global deterministic automata monitor, the second for monitors with per-cpu instances, and the third with per-task instances. Link: https://lkml.kernel.org/r/51b0bf425a281e226dfeba7401d2115d6091f84e.1659052063.git.bristot@kernel.org Cc: Wim Van Sebroeck Cc: Guenter Roeck Cc: Jonathan Corbet Cc: Ingo Molnar Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Will Deacon Cc: Catalin Marinas Cc: Marco Elver Cc: Dmitry Vyukov Cc: "Paul E. McKenney" Cc: Shuah Khan Cc: Gabriele Paoloni Cc: Juri Lelli Cc: Clark Williams Cc: Tao Zhou Cc: Randy Dunlap Cc: linux-doc@vger.kernel.org Cc: linux-kernel@vger.kernel.org Cc: linux-trace-devel@vger.kernel.org Signed-off-by: Daniel Bristot de Oliveira Signed-off-by: Steven Rostedt (Google) --- include/trace/events/rv.h | 120 ++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 120 insertions(+) create mode 100644 include/trace/events/rv.h (limited to 'include/trace/events') diff --git a/include/trace/events/rv.h b/include/trace/events/rv.h new file mode 100644 index 000000000000..20a2e09c6416 --- /dev/null +++ b/include/trace/events/rv.h @@ -0,0 +1,120 @@ +/* SPDX-License-Identifier: GPL-2.0 */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM rv + +#if !defined(_TRACE_RV_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_RV_H + +#include +#include + +#ifdef CONFIG_DA_MON_EVENTS_IMPLICIT +DECLARE_EVENT_CLASS(event_da_monitor, + + TP_PROTO(char *state, char *event, char *next_state, bool final_state), + + TP_ARGS(state, event, next_state, final_state), + + TP_STRUCT__entry( + __array( char, state, MAX_DA_NAME_LEN ) + __array( char, event, MAX_DA_NAME_LEN ) + __array( char, next_state, MAX_DA_NAME_LEN ) + __field( bool, final_state ) + ), + + TP_fast_assign( + memcpy(__entry->state, state, MAX_DA_NAME_LEN); + memcpy(__entry->event, event, MAX_DA_NAME_LEN); + memcpy(__entry->next_state, next_state, MAX_DA_NAME_LEN); + __entry->final_state = final_state; + ), + + TP_printk("%s x %s -> %s %s", + __entry->state, + __entry->event, + __entry->next_state, + __entry->final_state ? "(final)" : "") +); + +DECLARE_EVENT_CLASS(error_da_monitor, + + TP_PROTO(char *state, char *event), + + TP_ARGS(state, event), + + TP_STRUCT__entry( + __array( char, state, MAX_DA_NAME_LEN ) + __array( char, event, MAX_DA_NAME_LEN ) + ), + + TP_fast_assign( + memcpy(__entry->state, state, MAX_DA_NAME_LEN); + memcpy(__entry->event, event, MAX_DA_NAME_LEN); + ), + + TP_printk("event %s not expected in the state %s", + __entry->event, + __entry->state) +); +#endif /* CONFIG_DA_MON_EVENTS_IMPLICIT */ + +#ifdef CONFIG_DA_MON_EVENTS_ID +DECLARE_EVENT_CLASS(event_da_monitor_id, + + TP_PROTO(int id, char *state, char *event, char *next_state, bool final_state), + + TP_ARGS(id, state, event, next_state, final_state), + + TP_STRUCT__entry( + __field( int, id ) + __array( char, state, MAX_DA_NAME_LEN ) + __array( char, event, MAX_DA_NAME_LEN ) + __array( char, next_state, MAX_DA_NAME_LEN ) + __field( bool, final_state ) + ), + + TP_fast_assign( + memcpy(__entry->state, state, MAX_DA_NAME_LEN); + memcpy(__entry->event, event, MAX_DA_NAME_LEN); + memcpy(__entry->next_state, next_state, MAX_DA_NAME_LEN); + __entry->id = id; + __entry->final_state = final_state; + ), + + TP_printk("%d: %s x %s -> %s %s", + __entry->id, + __entry->state, + __entry->event, + __entry->next_state, + __entry->final_state ? "(final)" : "") +); + +DECLARE_EVENT_CLASS(error_da_monitor_id, + + TP_PROTO(int id, char *state, char *event), + + TP_ARGS(id, state, event), + + TP_STRUCT__entry( + __field( int, id ) + __array( char, state, MAX_DA_NAME_LEN ) + __array( char, event, MAX_DA_NAME_LEN ) + ), + + TP_fast_assign( + memcpy(__entry->state, state, MAX_DA_NAME_LEN); + memcpy(__entry->event, event, MAX_DA_NAME_LEN); + __entry->id = id; + ), + + TP_printk("%d: event %s not expected in the state %s", + __entry->id, + __entry->event, + __entry->state) +); +#endif /* CONFIG_DA_MON_EVENTS_ID */ +#endif /* _TRACE_RV_H */ + +/* This part ust be outside protection */ +#undef TRACE_INCLUDE_PATH +#include -- cgit v1.2.3 From 10bde81c74863472047f31304064018c40f488ee Mon Sep 17 00:00:00 2001 From: Daniel Bristot de Oliveira Date: Fri, 29 Jul 2022 11:38:52 +0200 Subject: rv/monitor: Add the wip monitor The wakeup in preemptive (wip) monitor verifies if the wakeup events always take place with preemption disabled: | | v #==================# H preemptive H <+ #==================# | | | | preempt_disable | preempt_enable v | sched_waking +------------------+ | +--------------- | | | | | non_preemptive | | +--------------> | | -+ +------------------+ The wakeup event always takes place with preemption disabled because of the scheduler synchronization. However, because the preempt_count and its trace event are not atomic with regard to interrupts, some inconsistencies might happen. The documentation illustrates one of these cases. Link: https://lkml.kernel.org/r/c98ca678df81115fddc04921b3c79720c836b18f.1659052063.git.bristot@kernel.org Cc: Wim Van Sebroeck Cc: Guenter Roeck Cc: Jonathan Corbet Cc: Ingo Molnar Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Will Deacon Cc: Catalin Marinas Cc: Marco Elver Cc: Dmitry Vyukov Cc: "Paul E. McKenney" Cc: Shuah Khan Cc: Gabriele Paoloni Cc: Juri Lelli Cc: Clark Williams Cc: Tao Zhou Cc: Randy Dunlap Cc: linux-doc@vger.kernel.org Cc: linux-kernel@vger.kernel.org Cc: linux-trace-devel@vger.kernel.org Signed-off-by: Daniel Bristot de Oliveira Signed-off-by: Steven Rostedt (Google) --- include/trace/events/rv.h | 10 ++++++++++ 1 file changed, 10 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/rv.h b/include/trace/events/rv.h index 20a2e09c6416..e972f27d8df3 100644 --- a/include/trace/events/rv.h +++ b/include/trace/events/rv.h @@ -56,6 +56,16 @@ DECLARE_EVENT_CLASS(error_da_monitor, __entry->event, __entry->state) ); + +#ifdef CONFIG_RV_MON_WIP +DEFINE_EVENT(event_da_monitor, event_wip, + TP_PROTO(char *state, char *event, char *next_state, bool final_state), + TP_ARGS(state, event, next_state, final_state)); + +DEFINE_EVENT(error_da_monitor, error_wip, + TP_PROTO(char *state, char *event), + TP_ARGS(state, event)); +#endif /* CONFIG_RV_MON_WIP */ #endif /* CONFIG_DA_MON_EVENTS_IMPLICIT */ #ifdef CONFIG_DA_MON_EVENTS_ID -- cgit v1.2.3 From ccc319dcb450d57b7befe924453d06804d83ba73 Mon Sep 17 00:00:00 2001 From: Daniel Bristot de Oliveira Date: Fri, 29 Jul 2022 11:38:53 +0200 Subject: rv/monitor: Add the wwnr monitor Per task wakeup while not running (wwnr) monitor. This model is broken, the reason is that a task can be running in the processor without being set as RUNNABLE. Think about a task about to sleep: 1: set_current_state(TASK_UNINTERRUPTIBLE); 2: schedule(); And then imagine an IRQ happening in between the lines one and two, waking the task up. BOOM, the wakeup will happen while the task is running. Q: Why do we need this model, so? A: To test the reactors. Link: https://lkml.kernel.org/r/473c0fc39967250fdebcff8b620311c11dccad30.1659052063.git.bristot@kernel.org Cc: Wim Van Sebroeck Cc: Guenter Roeck Cc: Jonathan Corbet Cc: Ingo Molnar Cc: Thomas Gleixner Cc: Peter Zijlstra Cc: Will Deacon Cc: Catalin Marinas Cc: Marco Elver Cc: Dmitry Vyukov Cc: "Paul E. McKenney" Cc: Shuah Khan Cc: Gabriele Paoloni Cc: Juri Lelli Cc: Clark Williams Cc: Tao Zhou Cc: Randy Dunlap Cc: linux-doc@vger.kernel.org Cc: linux-kernel@vger.kernel.org Cc: linux-trace-devel@vger.kernel.org Signed-off-by: Daniel Bristot de Oliveira Signed-off-by: Steven Rostedt (Google) --- include/trace/events/rv.h | 12 ++++++++++++ 1 file changed, 12 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/rv.h b/include/trace/events/rv.h index e972f27d8df3..56592da9301c 100644 --- a/include/trace/events/rv.h +++ b/include/trace/events/rv.h @@ -122,6 +122,18 @@ DECLARE_EVENT_CLASS(error_da_monitor_id, __entry->event, __entry->state) ); + +#ifdef CONFIG_RV_MON_WWNR +/* id is the pid of the task */ +DEFINE_EVENT(event_da_monitor_id, event_wwnr, + TP_PROTO(int id, char *state, char *event, char *next_state, bool final_state), + TP_ARGS(id, state, event, next_state, final_state)); + +DEFINE_EVENT(error_da_monitor_id, error_wwnr, + TP_PROTO(int id, char *state, char *event), + TP_ARGS(id, state, event)); +#endif /* CONFIG_RV_MON_WWNR */ + #endif /* CONFIG_DA_MON_EVENTS_ID */ #endif /* _TRACE_RV_H */ -- cgit v1.2.3 From c56f9ec8b20f931014574b943590c4d830109380 Mon Sep 17 00:00:00 2001 From: David Howells Date: Wed, 6 Jul 2022 10:52:14 +0100 Subject: afs: Use refcount_t rather than atomic_t Use refcount_t rather than atomic_t in afs to make use of the count checking facilities provided. Signed-off-by: David Howells Reviewed-by: Marc Dionne cc: linux-afs@lists.infradead.org Link: https://lore.kernel.org/r/165911277768.3745403.423349776836296452.stgit@warthog.procyon.org.uk/ # v1 --- include/trace/events/afs.h | 26 +++++++++++++------------- 1 file changed, 13 insertions(+), 13 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h index 499f5fabd20f..aa60f42a9763 100644 --- a/include/trace/events/afs.h +++ b/include/trace/events/afs.h @@ -728,14 +728,14 @@ TRACE_EVENT(afs_cb_call, TRACE_EVENT(afs_call, TP_PROTO(struct afs_call *call, enum afs_call_trace op, - int usage, int outstanding, const void *where), + int ref, int outstanding, const void *where), - TP_ARGS(call, op, usage, outstanding, where), + TP_ARGS(call, op, ref, outstanding, where), TP_STRUCT__entry( __field(unsigned int, call ) __field(int, op ) - __field(int, usage ) + __field(int, ref ) __field(int, outstanding ) __field(const void *, where ) ), @@ -743,15 +743,15 @@ TRACE_EVENT(afs_call, TP_fast_assign( __entry->call = call->debug_id; __entry->op = op; - __entry->usage = usage; + __entry->ref = ref; __entry->outstanding = outstanding; __entry->where = where; ), - TP_printk("c=%08x %s u=%d o=%d sp=%pSR", + TP_printk("c=%08x %s r=%d o=%d sp=%pSR", __entry->call, __print_symbolic(__entry->op, afs_call_traces), - __entry->usage, + __entry->ref, __entry->outstanding, __entry->where) ); @@ -1476,36 +1476,36 @@ TRACE_EVENT(afs_volume, __entry->reason = reason; ), - TP_printk("V=%llx %s u=%d", + TP_printk("V=%llx %s ur=%d", __entry->vid, __print_symbolic(__entry->reason, afs_volume_traces), __entry->ref) ); TRACE_EVENT(afs_cell, - TP_PROTO(unsigned int cell_debug_id, int usage, int active, + TP_PROTO(unsigned int cell_debug_id, int ref, int active, enum afs_cell_trace reason), - TP_ARGS(cell_debug_id, usage, active, reason), + TP_ARGS(cell_debug_id, ref, active, reason), TP_STRUCT__entry( __field(unsigned int, cell ) - __field(int, usage ) + __field(int, ref ) __field(int, active ) __field(int, reason ) ), TP_fast_assign( __entry->cell = cell_debug_id; - __entry->usage = usage; + __entry->ref = ref; __entry->active = active; __entry->reason = reason; ), - TP_printk("L=%08x %s u=%d a=%d", + TP_printk("L=%08x %s r=%d a=%d", __entry->cell, __print_symbolic(__entry->reason, afs_cell_traces), - __entry->usage, + __entry->ref, __entry->active) ); -- cgit v1.2.3 From 2757a4dc184997c66ef1de32636f73b9f21aac14 Mon Sep 17 00:00:00 2001 From: David Howells Date: Wed, 6 Jul 2022 11:26:14 +0100 Subject: afs: Fix access after dec in put functions Reference-putting functions should not access the object being put after decrementing the refcount unless they reduce the refcount to zero. Fix a couple of instances of this in afs by copying the information to be logged by tracepoint to local variables before doing the decrement. [Fixed a bit in afs_put_server() that I'd missed but Marc caught] Fixes: 341f741f04be ("afs: Refcount the afs_call struct") Fixes: 452181936931 ("afs: Trace afs_server usage") Fixes: 977e5f8ed0ab ("afs: Split the usage count on struct afs_server") Signed-off-by: David Howells cc: Marc Dionne cc: linux-afs@lists.infradead.org Link: https://lore.kernel.org/r/165911278430.3745403.16526310736054780645.stgit@warthog.procyon.org.uk/ # v1 --- include/trace/events/afs.h | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) (limited to 'include/trace/events') diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h index aa60f42a9763..e9d412d19dbb 100644 --- a/include/trace/events/afs.h +++ b/include/trace/events/afs.h @@ -727,10 +727,10 @@ TRACE_EVENT(afs_cb_call, ); TRACE_EVENT(afs_call, - TP_PROTO(struct afs_call *call, enum afs_call_trace op, + TP_PROTO(unsigned int call_debug_id, enum afs_call_trace op, int ref, int outstanding, const void *where), - TP_ARGS(call, op, ref, outstanding, where), + TP_ARGS(call_debug_id, op, ref, outstanding, where), TP_STRUCT__entry( __field(unsigned int, call ) @@ -741,7 +741,7 @@ TRACE_EVENT(afs_call, ), TP_fast_assign( - __entry->call = call->debug_id; + __entry->call = call_debug_id; __entry->op = op; __entry->ref = ref; __entry->outstanding = outstanding; @@ -1433,10 +1433,10 @@ TRACE_EVENT(afs_cb_miss, ); TRACE_EVENT(afs_server, - TP_PROTO(struct afs_server *server, int ref, int active, + TP_PROTO(unsigned int server_debug_id, int ref, int active, enum afs_server_trace reason), - TP_ARGS(server, ref, active, reason), + TP_ARGS(server_debug_id, ref, active, reason), TP_STRUCT__entry( __field(unsigned int, server ) @@ -1446,7 +1446,7 @@ TRACE_EVENT(afs_server, ), TP_fast_assign( - __entry->server = server->debug_id; + __entry->server = server_debug_id; __entry->ref = ref; __entry->active = active; __entry->reason = reason; -- cgit v1.2.3 From 6ab4b1990097b76508bd6dffd85ffcacbedb26b2 Mon Sep 17 00:00:00 2001 From: Kajetan Puchalski Date: Tue, 26 Jul 2022 11:24:04 +0100 Subject: cpuidle: Add cpu_idle_miss trace event Add a trace event for cpuidle to track missed (too deep or too shallow) wakeups. After each wakeup, CPUIdle already computes whether the entered state was optimal, above or below the desired one and updates the relevant counters. This patch makes it possible to trace those events in addition to just reading the counters. The patterns of types and percentages of misses across different workloads appear to be very consistent. This makes the trace event very useful for comparing the relative correctness of different CPUIdle governors for different types of workloads, or for finding the optimal governor for a given device. Signed-off-by: Kajetan Puchalski Reviewed-by: Steven Rostedt (Google) Signed-off-by: Rafael J. Wysocki --- include/trace/events/power.h | 22 ++++++++++++++++++++++ 1 file changed, 22 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/power.h b/include/trace/events/power.h index c708521e4ed5..77f14f7a11d4 100644 --- a/include/trace/events/power.h +++ b/include/trace/events/power.h @@ -40,6 +40,28 @@ DEFINE_EVENT(cpu, cpu_idle, TP_ARGS(state, cpu_id) ); +TRACE_EVENT(cpu_idle_miss, + + TP_PROTO(unsigned int cpu_id, unsigned int state, bool below), + + TP_ARGS(cpu_id, state, below), + + TP_STRUCT__entry( + __field(u32, cpu_id) + __field(u32, state) + __field(bool, below) + ), + + TP_fast_assign( + __entry->cpu_id = cpu_id; + __entry->state = state; + __entry->below = below; + ), + + TP_printk("cpu_id=%lu state=%lu type=%s", (unsigned long)__entry->cpu_id, + (unsigned long)__entry->state, (__entry->below)?"below":"above") +); + TRACE_EVENT(powernv_throttle, TP_PROTO(int chip_id, const char *reason, int pmax), -- cgit v1.2.3 From 1a1e3aca9d4957e282945cdc2b58e7c560b8e0d2 Mon Sep 17 00:00:00 2001 From: Jeff Layton Date: Fri, 5 Aug 2022 06:43:48 -0400 Subject: fscache: add tracepoint when failing cookie Signed-off-by: Jeff Layton Signed-off-by: David Howells --- include/trace/events/fscache.h | 2 ++ 1 file changed, 2 insertions(+) (limited to 'include/trace/events') diff --git a/include/trace/events/fscache.h b/include/trace/events/fscache.h index cb3fb337e880..c078c48a8e6d 100644 --- a/include/trace/events/fscache.h +++ b/include/trace/events/fscache.h @@ -49,6 +49,7 @@ enum fscache_volume_trace { enum fscache_cookie_trace { fscache_cookie_collision, fscache_cookie_discard, + fscache_cookie_failed, fscache_cookie_get_attach_object, fscache_cookie_get_end_access, fscache_cookie_get_hash_collision, @@ -131,6 +132,7 @@ enum fscache_access_trace { #define fscache_cookie_traces \ EM(fscache_cookie_collision, "*COLLIDE*") \ EM(fscache_cookie_discard, "DISCARD ") \ + EM(fscache_cookie_failed, "FAILED ") \ EM(fscache_cookie_get_attach_object, "GET attch") \ EM(fscache_cookie_get_hash_collision, "GET hcoll") \ EM(fscache_cookie_get_end_access, "GQ endac") \ -- cgit v1.2.3 From 1685c0f32554a7f35962061d17155c58454f1cd2 Mon Sep 17 00:00:00 2001 From: Mingwei Zhang Date: Sun, 7 Aug 2022 05:21:41 +0000 Subject: KVM: x86/mmu: rename trace function name for asynchronous page fault Rename the tracepoint function from trace_kvm_async_pf_doublefault() to trace_kvm_async_pf_repeated_fault() to make it clear, since double fault has nothing to do with this trace function. Asynchronous Page Fault (APF) is an artifact generated by KVM when it cannot find a physical page to satisfy an EPT violation. KVM uses APF to tell the guest OS to do something else such as scheduling other guest processes to make forward progress. However, when another guest process also touches a previously APFed page, KVM halts the vCPU instead of generating a repeated APF to avoid wasting cycles. Double fault (#DF) clearly has a different meaning and a different consequence when triggered. #DF requires two nested contributory exceptions instead of two page faults faulting at the same address. A prevous bug on APF indicates that it may trigger a double fault in the guest [1] and clearly this trace function has nothing to do with it. So rename this function should be a valid choice. No functional change intended. [1] https://www.spinics.net/lists/kvm/msg214957.html Signed-off-by: Mingwei Zhang Message-Id: <20220807052141.69186-1-mizhang@google.com> Signed-off-by: Paolo Bonzini --- include/trace/events/kvm.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'include/trace/events') diff --git a/include/trace/events/kvm.h b/include/trace/events/kvm.h index 37e1e1a2d67d..3bd31ea23fee 100644 --- a/include/trace/events/kvm.h +++ b/include/trace/events/kvm.h @@ -282,7 +282,7 @@ DEFINE_EVENT(kvm_async_get_page_class, kvm_try_async_get_page, TP_ARGS(gva, gfn) ); -DEFINE_EVENT(kvm_async_get_page_class, kvm_async_pf_doublefault, +DEFINE_EVENT(kvm_async_get_page_class, kvm_async_pf_repeated_fault, TP_PROTO(u64 gva, u64 gfn), -- cgit v1.2.3 From 9cb252c4c1c53ae58bc565bab76e98133288f23a Mon Sep 17 00:00:00 2001 From: Menglong Dong Date: Mon, 5 Sep 2022 11:50:15 +0800 Subject: net: skb: export skb drop reaons to user by TRACE_DEFINE_ENUM As Eric reported, the 'reason' field is not presented when trace the kfree_skb event by perf: $ perf record -e skb:kfree_skb -a sleep 10 $ perf script ip_defrag 14605 [021] 221.614303: skb:kfree_skb: skbaddr=0xffff9d2851242700 protocol=34525 location=0xffffffffa39346b1 reason: The cause seems to be passing kernel address directly to TP_printk(), which is not right. As the enum 'skb_drop_reason' is not exported to user space through TRACE_DEFINE_ENUM(), perf can't get the drop reason string from the 'reason' field, which is a number. Therefore, we introduce the macro DEFINE_DROP_REASON(), which is used to define the trace enum by TRACE_DEFINE_ENUM(). With the help of DEFINE_DROP_REASON(), now we can remove the auto-generate that we introduced in the commit ec43908dd556 ("net: skb: use auto-generation to convert skb drop reason to string"), and define the string array 'drop_reasons'. Hmmmm...now we come back to the situation that have to maintain drop reasons in both enum skb_drop_reason and DEFINE_DROP_REASON. But they are both in dropreason.h, which makes it easier. After this commit, now the format of kfree_skb is like this: $ cat /tracing/events/skb/kfree_skb/format name: kfree_skb ID: 1524 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:void * skbaddr; offset:8; size:8; signed:0; field:void * location; offset:16; size:8; signed:0; field:unsigned short protocol; offset:24; size:2; signed:0; field:enum skb_drop_reason reason; offset:28; size:4; signed:0; print fmt: "skbaddr=%p protocol=%u location=%p reason: %s", REC->skbaddr, REC->protocol, REC->location, __print_symbolic(REC->reason, { 1, "NOT_SPECIFIED" }, { 2, "NO_SOCKET" } ...... Fixes: ec43908dd556 ("net: skb: use auto-generation to convert skb drop reason to string") Link: https://lore.kernel.org/netdev/CANn89i+bx0ybvE55iMYf5GJM48WwV1HNpdm9Q6t-HaEstqpCSA@mail.gmail.com/ Reported-by: Eric Dumazet Signed-off-by: Menglong Dong Signed-off-by: David S. Miller --- include/trace/events/skb.h | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) (limited to 'include/trace/events') diff --git a/include/trace/events/skb.h b/include/trace/events/skb.h index 45264e4bb254..50a974f7dfb4 100644 --- a/include/trace/events/skb.h +++ b/include/trace/events/skb.h @@ -9,6 +9,15 @@ #include #include +#undef FN +#define FN(reason) TRACE_DEFINE_ENUM(SKB_DROP_REASON_##reason); +DEFINE_DROP_REASON(FN, FN) + +#undef FN +#undef FNe +#define FN(reason) { SKB_DROP_REASON_##reason, #reason }, +#define FNe(reason) { SKB_DROP_REASON_##reason, #reason } + /* * Tracepoint for free an sk_buff: */ @@ -35,9 +44,13 @@ TRACE_EVENT(kfree_skb, TP_printk("skbaddr=%p protocol=%u location=%p reason: %s", __entry->skbaddr, __entry->protocol, __entry->location, - drop_reasons[__entry->reason]) + __print_symbolic(__entry->reason, + DEFINE_DROP_REASON(FN, FNe))) ); +#undef FN +#undef FNe + TRACE_EVENT(consume_skb, TP_PROTO(struct sk_buff *skb), -- cgit v1.2.3