diff mbox series

[6/7] tracing: add support for function argument to graph tracer

Message ID 20240904065908.1009086-7-svens@linux.ibm.com (mailing list archive)
State New
Delegated to: Masami Hiramatsu
Headers show
Series add function arguments to ftrace | expand

Commit Message

Sven Schnelle Sept. 4, 2024, 6:59 a.m. UTC
Wire up the code to print function arguments in the function graph
tracer. This functionality can be enabled/disabled during compile
time by setting CONFIG_FUNCTION_TRACE_ARGS and during runtime with
options/funcgraph-args.

Example usage:

6)              | dummy_xmit [dummy](skb = 0x8887c100, dev = 0x872ca000) {
6)              |   consume_skb(skb = 0x8887c100) {
6)              |     skb_release_head_state(skb = 0x8887c100) {
6)  0.178 us    |       sock_wfree(skb = 0x8887c100)
6)  0.627 us    |     }

Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
---
 include/linux/ftrace.h               |  1 +
 kernel/trace/fgraph.c                |  6 ++-
 kernel/trace/trace_functions_graph.c | 74 ++++++++++++++--------------
 3 files changed, 44 insertions(+), 37 deletions(-)

Comments

kernel test robot Sept. 5, 2024, 8:05 a.m. UTC | #1
Hi Sven,

kernel test robot noticed the following build errors:

[auto build test ERROR on s390/features]
[also build test ERROR on tip/x86/core linus/master v6.11-rc6]
[cannot apply to rostedt-trace/for-next rostedt-trace/for-next-urgent next-20240904]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Sven-Schnelle/tracing-add-ftrace_regs-to-function_graph_enter/20240904-150232
base:   https://git.kernel.org/pub/scm/linux/kernel/git/s390/linux.git features
patch link:    https://lore.kernel.org/r/20240904065908.1009086-7-svens%40linux.ibm.com
patch subject: [PATCH 6/7] tracing: add support for function argument to graph tracer
config: openrisc-allnoconfig (https://download.01.org/0day-ci/archive/20240905/202409051539.ZmGpuZIP-lkp@intel.com/config)
compiler: or1k-linux-gcc (GCC) 14.1.0
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20240905/202409051539.ZmGpuZIP-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202409051539.ZmGpuZIP-lkp@intel.com/

All errors (new ones prefixed by >>):

   In file included from include/linux/perf_event.h:52,
                    from include/linux/trace_events.h:10,
                    from include/trace/syscall.h:7,
                    from include/linux/syscalls.h:93,
                    from kernel/time/time.c:33:
>> include/linux/ftrace.h:1013:28: error: field 'regs' has incomplete type
    1013 |         struct ftrace_regs regs;
         |                            ^~~~
--
   In file included from include/linux/perf_event.h:52,
                    from include/linux/trace_events.h:10,
                    from include/trace/syscall.h:7,
                    from include/linux/syscalls.h:93,
                    from kernel/time/hrtimer.c:30:
>> include/linux/ftrace.h:1013:28: error: field 'regs' has incomplete type
    1013 |         struct ftrace_regs regs;
         |                            ^~~~
   kernel/time/hrtimer.c:121:35: warning: initialized field overwritten [-Woverride-init]
     121 |         [CLOCK_REALTIME]        = HRTIMER_BASE_REALTIME,
         |                                   ^~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:121:35: note: (near initialization for 'hrtimer_clock_to_base_table[0]')
   kernel/time/hrtimer.c:122:35: warning: initialized field overwritten [-Woverride-init]
     122 |         [CLOCK_MONOTONIC]       = HRTIMER_BASE_MONOTONIC,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:122:35: note: (near initialization for 'hrtimer_clock_to_base_table[1]')
   kernel/time/hrtimer.c:123:35: warning: initialized field overwritten [-Woverride-init]
     123 |         [CLOCK_BOOTTIME]        = HRTIMER_BASE_BOOTTIME,
         |                                   ^~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:123:35: note: (near initialization for 'hrtimer_clock_to_base_table[7]')
   kernel/time/hrtimer.c:124:35: warning: initialized field overwritten [-Woverride-init]
     124 |         [CLOCK_TAI]             = HRTIMER_BASE_TAI,
         |                                   ^~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:124:35: note: (near initialization for 'hrtimer_clock_to_base_table[11]')


vim +/regs +1013 include/linux/ftrace.h

  1006	
  1007	/*
  1008	 * Structure that defines an entry function trace.
  1009	 * It's already packed but the attribute "packed" is needed
  1010	 * to remove extra padding at the end.
  1011	 */
  1012	struct ftrace_graph_ent {
> 1013		struct ftrace_regs regs;
  1014		unsigned long func; /* Current function */
  1015		int depth;
  1016	} __packed;
  1017
kernel test robot Sept. 5, 2024, 8:36 a.m. UTC | #2
Hi Sven,

kernel test robot noticed the following build errors:

[auto build test ERROR on s390/features]
[also build test ERROR on tip/x86/core linus/master v6.11-rc6]
[cannot apply to rostedt-trace/for-next rostedt-trace/for-next-urgent next-20240904]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Sven-Schnelle/tracing-add-ftrace_regs-to-function_graph_enter/20240904-150232
base:   https://git.kernel.org/pub/scm/linux/kernel/git/s390/linux.git features
patch link:    https://lore.kernel.org/r/20240904065908.1009086-7-svens%40linux.ibm.com
patch subject: [PATCH 6/7] tracing: add support for function argument to graph tracer
config: um-allnoconfig (https://download.01.org/0day-ci/archive/20240905/202409051644.nZ4Nj2uc-lkp@intel.com/config)
compiler: clang version 17.0.6 (https://github.com/llvm/llvm-project 6009708b4367171ccdbf4b5905cb6a803753fe18)
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20240905/202409051644.nZ4Nj2uc-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202409051644.nZ4Nj2uc-lkp@intel.com/

All errors (new ones prefixed by >>):

   In file included from kernel/fork.c:34:
   In file included from include/linux/mempolicy.h:15:
   In file included from include/linux/pagemap.h:11:
   In file included from include/linux/highmem.h:12:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:548:31: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     548 |         val = __raw_readb(PCI_IOBASE + addr);
         |                           ~~~~~~~~~~ ^
   include/asm-generic/io.h:561:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     561 |         val = __le16_to_cpu((__le16 __force)__raw_readw(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:37:51: note: expanded from macro '__le16_to_cpu'
      37 | #define __le16_to_cpu(x) ((__force __u16)(__le16)(x))
         |                                                   ^
   In file included from kernel/fork.c:34:
   In file included from include/linux/mempolicy.h:15:
   In file included from include/linux/pagemap.h:11:
   In file included from include/linux/highmem.h:12:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:574:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     574 |         val = __le32_to_cpu((__le32 __force)__raw_readl(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:35:51: note: expanded from macro '__le32_to_cpu'
      35 | #define __le32_to_cpu(x) ((__force __u32)(__le32)(x))
         |                                                   ^
   In file included from kernel/fork.c:34:
   In file included from include/linux/mempolicy.h:15:
   In file included from include/linux/pagemap.h:11:
   In file included from include/linux/highmem.h:12:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:585:33: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     585 |         __raw_writeb(value, PCI_IOBASE + addr);
         |                             ~~~~~~~~~~ ^
   include/asm-generic/io.h:595:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     595 |         __raw_writew((u16 __force)cpu_to_le16(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:605:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     605 |         __raw_writel((u32 __force)cpu_to_le32(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:693:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     693 |         readsb(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:701:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     701 |         readsw(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:709:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     709 |         readsl(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:718:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     718 |         writesb(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:727:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     727 |         writesw(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:736:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     736 |         writesl(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   In file included from kernel/fork.c:56:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:10:
   In file included from include/linux/perf_event.h:52:
>> include/linux/ftrace.h:1013:21: error: field has incomplete type 'struct ftrace_regs'
    1013 |         struct ftrace_regs regs;
         |                            ^
   include/linux/ftrace.h:41:8: note: forward declaration of 'struct ftrace_regs'
      41 | struct ftrace_regs;
         |        ^
   12 warnings and 1 error generated.
--
   In file included from kernel/signal.c:27:
   In file included from include/linux/tty.h:11:
   In file included from include/linux/tty_port.h:5:
   In file included from include/linux/kfifo.h:40:
   In file included from include/linux/dma-mapping.h:11:
   In file included from include/linux/scatterlist.h:9:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:548:31: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     548 |         val = __raw_readb(PCI_IOBASE + addr);
         |                           ~~~~~~~~~~ ^
   include/asm-generic/io.h:561:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     561 |         val = __le16_to_cpu((__le16 __force)__raw_readw(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:37:51: note: expanded from macro '__le16_to_cpu'
      37 | #define __le16_to_cpu(x) ((__force __u16)(__le16)(x))
         |                                                   ^
   In file included from kernel/signal.c:27:
   In file included from include/linux/tty.h:11:
   In file included from include/linux/tty_port.h:5:
   In file included from include/linux/kfifo.h:40:
   In file included from include/linux/dma-mapping.h:11:
   In file included from include/linux/scatterlist.h:9:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:574:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     574 |         val = __le32_to_cpu((__le32 __force)__raw_readl(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:35:51: note: expanded from macro '__le32_to_cpu'
      35 | #define __le32_to_cpu(x) ((__force __u32)(__le32)(x))
         |                                                   ^
   In file included from kernel/signal.c:27:
   In file included from include/linux/tty.h:11:
   In file included from include/linux/tty_port.h:5:
   In file included from include/linux/kfifo.h:40:
   In file included from include/linux/dma-mapping.h:11:
   In file included from include/linux/scatterlist.h:9:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:585:33: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     585 |         __raw_writeb(value, PCI_IOBASE + addr);
         |                             ~~~~~~~~~~ ^
   include/asm-generic/io.h:595:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     595 |         __raw_writew((u16 __force)cpu_to_le16(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:605:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     605 |         __raw_writel((u32 __force)cpu_to_le32(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:693:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     693 |         readsb(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:701:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     701 |         readsw(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:709:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     709 |         readsl(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:718:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     718 |         writesb(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:727:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     727 |         writesw(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:736:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     736 |         writesl(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   In file included from kernel/signal.c:31:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:10:
   In file included from include/linux/perf_event.h:52:
>> include/linux/ftrace.h:1013:21: error: field has incomplete type 'struct ftrace_regs'
    1013 |         struct ftrace_regs regs;
         |                            ^
   include/linux/ftrace.h:41:8: note: forward declaration of 'struct ftrace_regs'
      41 | struct ftrace_regs;
         |        ^
   kernel/signal.c:140:37: warning: array index 3 is past the end of the array (that has type 'unsigned long[2]') [-Warray-bounds]
     140 |         case 4: ready  = signal->sig[3] &~ blocked->sig[3];
         |                                            ^            ~
   arch/x86/include/asm/signal.h:24:2: note: array 'sig' declared here
      24 |         unsigned long sig[_NSIG_WORDS];
         |         ^
   kernel/signal.c:140:19: warning: array index 3 is past the end of the array (that has type 'unsigned long[2]') [-Warray-bounds]
     140 |         case 4: ready  = signal->sig[3] &~ blocked->sig[3];
         |                          ^           ~
   arch/x86/include/asm/signal.h:24:2: note: array 'sig' declared here
      24 |         unsigned long sig[_NSIG_WORDS];
         |         ^
   kernel/signal.c:141:30: warning: array index 2 is past the end of the array (that has type 'unsigned long[2]') [-Warray-bounds]
     141 |                 ready |= signal->sig[2] &~ blocked->sig[2];
         |                                            ^            ~
   arch/x86/include/asm/signal.h:24:2: note: array 'sig' declared here
      24 |         unsigned long sig[_NSIG_WORDS];
         |         ^
   kernel/signal.c:141:12: warning: array index 2 is past the end of the array (that has type 'unsigned long[2]') [-Warray-bounds]
     141 |                 ready |= signal->sig[2] &~ blocked->sig[2];
         |                          ^           ~
   arch/x86/include/asm/signal.h:24:2: note: array 'sig' declared here
      24 |         unsigned long sig[_NSIG_WORDS];
         |         ^
   16 warnings and 1 error generated.
--
   In file included from kernel/time/hrtimer.c:30:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:9:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:548:31: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     548 |         val = __raw_readb(PCI_IOBASE + addr);
         |                           ~~~~~~~~~~ ^
   include/asm-generic/io.h:561:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     561 |         val = __le16_to_cpu((__le16 __force)__raw_readw(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:37:51: note: expanded from macro '__le16_to_cpu'
      37 | #define __le16_to_cpu(x) ((__force __u16)(__le16)(x))
         |                                                   ^
   In file included from kernel/time/hrtimer.c:30:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:9:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:574:61: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     574 |         val = __le32_to_cpu((__le32 __force)__raw_readl(PCI_IOBASE + addr));
         |                                                         ~~~~~~~~~~ ^
   include/uapi/linux/byteorder/little_endian.h:35:51: note: expanded from macro '__le32_to_cpu'
      35 | #define __le32_to_cpu(x) ((__force __u32)(__le32)(x))
         |                                                   ^
   In file included from kernel/time/hrtimer.c:30:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:9:
   In file included from include/linux/hardirq.h:11:
   In file included from arch/um/include/asm/hardirq.h:5:
   In file included from include/asm-generic/hardirq.h:17:
   In file included from include/linux/irq.h:20:
   In file included from include/linux/io.h:14:
   In file included from arch/um/include/asm/io.h:24:
   include/asm-generic/io.h:585:33: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     585 |         __raw_writeb(value, PCI_IOBASE + addr);
         |                             ~~~~~~~~~~ ^
   include/asm-generic/io.h:595:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     595 |         __raw_writew((u16 __force)cpu_to_le16(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:605:59: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     605 |         __raw_writel((u32 __force)cpu_to_le32(value), PCI_IOBASE + addr);
         |                                                       ~~~~~~~~~~ ^
   include/asm-generic/io.h:693:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     693 |         readsb(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:701:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     701 |         readsw(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:709:20: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     709 |         readsl(PCI_IOBASE + addr, buffer, count);
         |                ~~~~~~~~~~ ^
   include/asm-generic/io.h:718:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     718 |         writesb(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:727:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     727 |         writesw(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   include/asm-generic/io.h:736:21: warning: performing pointer arithmetic on a null pointer has undefined behavior [-Wnull-pointer-arithmetic]
     736 |         writesl(PCI_IOBASE + addr, buffer, count);
         |                 ~~~~~~~~~~ ^
   In file included from kernel/time/hrtimer.c:30:
   In file included from include/linux/syscalls.h:93:
   In file included from include/trace/syscall.h:7:
   In file included from include/linux/trace_events.h:10:
   In file included from include/linux/perf_event.h:52:
>> include/linux/ftrace.h:1013:21: error: field has incomplete type 'struct ftrace_regs'
    1013 |         struct ftrace_regs regs;
         |                            ^
   include/linux/ftrace.h:41:8: note: forward declaration of 'struct ftrace_regs'
      41 | struct ftrace_regs;
         |        ^
   kernel/time/hrtimer.c:121:21: warning: initializer overrides prior initialization of this subobject [-Winitializer-overrides]
     121 |         [CLOCK_REALTIME]        = HRTIMER_BASE_REALTIME,
         |                                   ^~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:119:27: note: previous initialization is here
     119 |         [0 ... MAX_CLOCKS - 1]  = HRTIMER_MAX_CLOCK_BASES,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:122:22: warning: initializer overrides prior initialization of this subobject [-Winitializer-overrides]
     122 |         [CLOCK_MONOTONIC]       = HRTIMER_BASE_MONOTONIC,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:119:27: note: previous initialization is here
     119 |         [0 ... MAX_CLOCKS - 1]  = HRTIMER_MAX_CLOCK_BASES,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:123:21: warning: initializer overrides prior initialization of this subobject [-Winitializer-overrides]
     123 |         [CLOCK_BOOTTIME]        = HRTIMER_BASE_BOOTTIME,
         |                                   ^~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:119:27: note: previous initialization is here
     119 |         [0 ... MAX_CLOCKS - 1]  = HRTIMER_MAX_CLOCK_BASES,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:124:17: warning: initializer overrides prior initialization of this subobject [-Winitializer-overrides]
     124 |         [CLOCK_TAI]             = HRTIMER_BASE_TAI,
         |                                   ^~~~~~~~~~~~~~~~
   kernel/time/hrtimer.c:119:27: note: previous initialization is here
     119 |         [0 ... MAX_CLOCKS - 1]  = HRTIMER_MAX_CLOCK_BASES,
         |                                   ^~~~~~~~~~~~~~~~~~~~~~~
   16 warnings and 1 error generated.


vim +1013 include/linux/ftrace.h

  1006	
  1007	/*
  1008	 * Structure that defines an entry function trace.
  1009	 * It's already packed but the attribute "packed" is needed
  1010	 * to remove extra padding at the end.
  1011	 */
  1012	struct ftrace_graph_ent {
> 1013		struct ftrace_regs regs;
  1014		unsigned long func; /* Current function */
  1015		int depth;
  1016	} __packed;
  1017
Steven Rostedt Oct. 4, 2024, 10:40 p.m. UTC | #3
On Wed,  4 Sep 2024 08:59:00 +0200
Sven Schnelle <svens@linux.ibm.com> wrote:

> Wire up the code to print function arguments in the function graph
> tracer. This functionality can be enabled/disabled during compile
> time by setting CONFIG_FUNCTION_TRACE_ARGS and during runtime with
> options/funcgraph-args.

I finally got around to looking at your patches. Do you plan on still
working on them? I really like this feature, and I'm willing to do the work
too if you have other things on your plate.

> 
> Example usage:
> 
> 6)              | dummy_xmit [dummy](skb = 0x8887c100, dev = 0x872ca000) {
> 6)              |   consume_skb(skb = 0x8887c100) {
> 6)              |     skb_release_head_state(skb = 0x8887c100) {
> 6)  0.178 us    |       sock_wfree(skb = 0x8887c100)
> 6)  0.627 us    |     }
> 
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> ---
>  include/linux/ftrace.h               |  1 +
>  kernel/trace/fgraph.c                |  6 ++-
>  kernel/trace/trace_functions_graph.c | 74 ++++++++++++++--------------
>  3 files changed, 44 insertions(+), 37 deletions(-)

BTW, this is missing:

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 2f8017f8d34d..8a218b39d11d 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -879,6 +879,7 @@ static __always_inline bool ftrace_hash_empty(struct ftrace_hash *hash)
 #define TRACE_GRAPH_GRAPH_TIME          0x400
 #define TRACE_GRAPH_PRINT_RETVAL        0x800
 #define TRACE_GRAPH_PRINT_RETVAL_HEX    0x1000
+#define TRACE_GRAPH_ARGS		0x2000
 #define TRACE_GRAPH_PRINT_FILL_SHIFT	28
 #define TRACE_GRAPH_PRINT_FILL_MASK	(0x3 << TRACE_GRAPH_PRINT_FILL_SHIFT)
 
that you added in patch 7, but is needed for this patch, where it does not
build without it.

> 
> diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> index 56d91041ecd2..5d0ff66f8a70 100644
> --- a/include/linux/ftrace.h
> +++ b/include/linux/ftrace.h
> @@ -1010,6 +1010,7 @@ static inline void ftrace_init(void) { }
>   * to remove extra padding at the end.
>   */
>  struct ftrace_graph_ent {
> +	struct ftrace_regs regs;
>  	unsigned long func; /* Current function */
>  	int depth;
>  } __packed;

This should have a different event type, to not waste the ring buffer when
not needed.

struct ftrace_graph_ent_args {
	struct ftrace_regs_args fargs;
	unsigned long func; /* Current function */
	int depth;
} __packed;

But also, we need to create a new structure, as nothing should depend on
the size of ftrace_regs (we plan on hiding that completely). I can add a
"struct ftrace_regs_args" that will hold just the args for each arch.
Especially for archs (like x86) where ftrace_regs can be pt_regs in size,
where most of the space is just wasted. Then we can do a:

	ftrace_regs_copy_args(fregs, &entry->addr);

And then:

	char buf[ftrace_regs_size()];
	struct ftrace_regs *fregs = &buf;

	ftrace_regs_from_args(fregs, &entry->addr);

to get the arguments.




> diff --git a/kernel/trace/fgraph.c b/kernel/trace/fgraph.c
> index fa62ebfa0711..f4bb10c0aa52 100644
> --- a/kernel/trace/fgraph.c
> +++ b/kernel/trace/fgraph.c
> @@ -614,7 +614,7 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func,
>  /* If the caller does not use ftrace, call this function. */
>  int function_graph_enter(unsigned long ret, unsigned long func,
>  			 unsigned long frame_pointer, unsigned long *retp,
> -			struct ftrace_regs *fregs)
> +			 struct ftrace_regs *fregs)
>  {
>  	struct ftrace_graph_ent trace;
>  	unsigned long bitmap = 0;
> @@ -623,6 +623,10 @@ int function_graph_enter(unsigned long ret, unsigned long func,
>  
>  	trace.func = func;
>  	trace.depth = ++current->curr_ret_depth;
> +	if (IS_ENABLED(CONFIG_FUNCTION_TRACE_ARGS) && fregs)
> +		trace.regs = *fregs;
> +	else
> +		memset(&trace.regs, 0, sizeof(struct ftrace_regs));
>  
>  	offset = ftrace_push_return_trace(ret, func, frame_pointer, retp, 0);
>  	if (offset < 0)
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 13d0387ac6a6..be0cee52944a 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -12,6 +12,8 @@
>  #include <linux/interrupt.h>
>  #include <linux/slab.h>
>  #include <linux/fs.h>
> +#include <linux/btf.h>
> +#include <linux/bpf.h>
>  
>  #include "trace.h"
>  #include "trace_output.h"
> @@ -63,6 +65,9 @@ static struct tracer_opt trace_opts[] = {
>  	{ TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
>  	/* Display function return value in hexadecimal format ? */
>  	{ TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
> +#endif
> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +	{ TRACER_OPT(funcgraph-args, TRACE_GRAPH_ARGS) },
>  #endif
>  	/* Include sleep time (scheduled out) between entry and return */
>  	{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
> @@ -653,7 +658,7 @@ print_graph_duration(struct trace_array *tr, unsigned long long duration,
>  #define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
>  
>  static void print_graph_retval(struct trace_seq *s, unsigned long retval,
> -				bool leaf, void *func, bool hex_format)
> +			       bool hex_format)
>  {
>  	unsigned long err_code = 0;
>  
> @@ -673,28 +678,17 @@ static void print_graph_retval(struct trace_seq *s, unsigned long retval,
>  		err_code = 0;
>  
>  done:
> -	if (leaf) {
> -		if (hex_format || (err_code == 0))
> -			trace_seq_printf(s, "%ps(); /* = 0x%lx */\n",
> -					func, retval);
> -		else
> -			trace_seq_printf(s, "%ps(); /* = %ld */\n",
> -					func, err_code);
> -	} else {
> -		if (hex_format || (err_code == 0))
> -			trace_seq_printf(s, "} /* %ps = 0x%lx */\n",
> -					func, retval);
> -		else
> -			trace_seq_printf(s, "} /* %ps = %ld */\n",
> -					func, err_code);
> -	}
> +	if (hex_format || (err_code == 0))
> +		trace_seq_printf(s, " /* = 0x%lx */", retval);
> +	else
> +		trace_seq_printf(s, " /* = %ld */", err_code);
>  }
>  
>  #else
>  
>  #define __TRACE_GRAPH_PRINT_RETVAL 0
>  
> -#define print_graph_retval(_seq, _retval, _leaf, _func, _format) do {} while (0)
> +#define print_graph_retval(_seq, _retval, _format) do {} while (0)
>  
>  #endif
>  
> @@ -741,16 +735,20 @@ print_graph_entry_leaf(struct trace_iterator *iter,
>  	/* Function */
>  	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
>  		trace_seq_putc(s, ' ');
> +	trace_seq_printf(s, "%ps", (void *)graph_ret->func);
> +	if (flags & TRACE_GRAPH_ARGS)
> +		print_function_args(s, &call->regs, graph_ret->func);

Ideally, the flag is going to be set when args is recorded and not used for
printing. If the event is the ftrace_ent_args() this will print the
arguments, otherwise it does not.

To simplify these functions, we probably need to have a:

union fgraph_entry {
	struct ftrace_graph_ent		*normal;
	struct ftrace_graph_ent_args	*args;
};

And switch depending which is which (the header of both is the same as is
for all entries).

-- Steve


> +	else
> +		trace_seq_puts(s, "();");
>  
>  	/*
>  	 * Write out the function return value if the option function-retval is
>  	 * enabled.
>  	 */
>  	if (flags & __TRACE_GRAPH_PRINT_RETVAL)
> -		print_graph_retval(s, graph_ret->retval, true, (void *)call->func,
> -				!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
> -	else
> -		trace_seq_printf(s, "%ps();\n", (void *)call->func);
> +		print_graph_retval(s, graph_ret->retval,
> +				   !!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
> +	trace_seq_printf(s, "\n");
>  
>  	print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
>  			cpu, iter->ent->pid, flags);
> @@ -788,7 +786,12 @@ print_graph_entry_nested(struct trace_iterator *iter,
>  	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
>  		trace_seq_putc(s, ' ');
>  
> -	trace_seq_printf(s, "%ps() {\n", (void *)call->func);
> +	trace_seq_printf(s, "%ps", (void *)call->func);
> +	if (flags & TRACE_GRAPH_ARGS)
> +		print_function_args(s, &call->regs, call->func);
> +	else
> +		trace_seq_puts(s, "()");
> +	trace_seq_printf(s, " {\n");
>  
>  	if (trace_seq_has_overflowed(s))
>  		return TRACE_TYPE_PARTIAL_LINE;
> @@ -1028,27 +1031,26 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
>  	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
>  		trace_seq_putc(s, ' ');
>  
> +	/*
> +	 * If the return function does not have a matching entry,
> +	 * then the entry was lost. Instead of just printing
> +	 * the '}' and letting the user guess what function this
> +	 * belongs to, write out the function name. Always do
> +	 * that if the funcgraph-tail option is enabled.
> +	 */
> +	if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
> +		trace_seq_puts(s, "}");
> +	else
> +		trace_seq_printf(s, "} /* %ps */", (void *)trace->func);
>  	/*
>  	 * Always write out the function name and its return value if the
>  	 * function-retval option is enabled.
>  	 */
>  	if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
> -		print_graph_retval(s, trace->retval, false, (void *)trace->func,
> +		print_graph_retval(s, trace->retval,
>  			!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
> -	} else {
> -		/*
> -		 * If the return function does not have a matching entry,
> -		 * then the entry was lost. Instead of just printing
> -		 * the '}' and letting the user guess what function this
> -		 * belongs to, write out the function name. Always do
> -		 * that if the funcgraph-tail option is enabled.
> -		 */
> -		if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
> -			trace_seq_puts(s, "}\n");
> -		else
> -			trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
>  	}
> -
> +	trace_seq_printf(s, "\n");
>  	/* Overrun */
>  	if (flags & TRACE_GRAPH_PRINT_OVERRUN)
>  		trace_seq_printf(s, " (Overruns: %u)\n",
Sven Schnelle Oct. 7, 2024, 6:37 a.m. UTC | #4
Steven Rostedt <rostedt@goodmis.org> writes:

> On Wed,  4 Sep 2024 08:59:00 +0200
> Sven Schnelle <svens@linux.ibm.com> wrote:
>
>> Wire up the code to print function arguments in the function graph
>> tracer. This functionality can be enabled/disabled during compile
>> time by setting CONFIG_FUNCTION_TRACE_ARGS and during runtime with
>> options/funcgraph-args.
>
> I finally got around to looking at your patches. Do you plan on still
> working on them? I really like this feature, and I'm willing to do the work
> too if you have other things on your plate.

Yes, working on other things, so feel free to take over.
diff mbox series

Patch

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 56d91041ecd2..5d0ff66f8a70 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -1010,6 +1010,7 @@  static inline void ftrace_init(void) { }
  * to remove extra padding at the end.
  */
 struct ftrace_graph_ent {
+	struct ftrace_regs regs;
 	unsigned long func; /* Current function */
 	int depth;
 } __packed;
diff --git a/kernel/trace/fgraph.c b/kernel/trace/fgraph.c
index fa62ebfa0711..f4bb10c0aa52 100644
--- a/kernel/trace/fgraph.c
+++ b/kernel/trace/fgraph.c
@@ -614,7 +614,7 @@  ftrace_push_return_trace(unsigned long ret, unsigned long func,
 /* If the caller does not use ftrace, call this function. */
 int function_graph_enter(unsigned long ret, unsigned long func,
 			 unsigned long frame_pointer, unsigned long *retp,
-			struct ftrace_regs *fregs)
+			 struct ftrace_regs *fregs)
 {
 	struct ftrace_graph_ent trace;
 	unsigned long bitmap = 0;
@@ -623,6 +623,10 @@  int function_graph_enter(unsigned long ret, unsigned long func,
 
 	trace.func = func;
 	trace.depth = ++current->curr_ret_depth;
+	if (IS_ENABLED(CONFIG_FUNCTION_TRACE_ARGS) && fregs)
+		trace.regs = *fregs;
+	else
+		memset(&trace.regs, 0, sizeof(struct ftrace_regs));
 
 	offset = ftrace_push_return_trace(ret, func, frame_pointer, retp, 0);
 	if (offset < 0)
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 13d0387ac6a6..be0cee52944a 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -12,6 +12,8 @@ 
 #include <linux/interrupt.h>
 #include <linux/slab.h>
 #include <linux/fs.h>
+#include <linux/btf.h>
+#include <linux/bpf.h>
 
 #include "trace.h"
 #include "trace_output.h"
@@ -63,6 +65,9 @@  static struct tracer_opt trace_opts[] = {
 	{ TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
 	/* Display function return value in hexadecimal format ? */
 	{ TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
+#endif
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+	{ TRACER_OPT(funcgraph-args, TRACE_GRAPH_ARGS) },
 #endif
 	/* Include sleep time (scheduled out) between entry and return */
 	{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
@@ -653,7 +658,7 @@  print_graph_duration(struct trace_array *tr, unsigned long long duration,
 #define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
 
 static void print_graph_retval(struct trace_seq *s, unsigned long retval,
-				bool leaf, void *func, bool hex_format)
+			       bool hex_format)
 {
 	unsigned long err_code = 0;
 
@@ -673,28 +678,17 @@  static void print_graph_retval(struct trace_seq *s, unsigned long retval,
 		err_code = 0;
 
 done:
-	if (leaf) {
-		if (hex_format || (err_code == 0))
-			trace_seq_printf(s, "%ps(); /* = 0x%lx */\n",
-					func, retval);
-		else
-			trace_seq_printf(s, "%ps(); /* = %ld */\n",
-					func, err_code);
-	} else {
-		if (hex_format || (err_code == 0))
-			trace_seq_printf(s, "} /* %ps = 0x%lx */\n",
-					func, retval);
-		else
-			trace_seq_printf(s, "} /* %ps = %ld */\n",
-					func, err_code);
-	}
+	if (hex_format || (err_code == 0))
+		trace_seq_printf(s, " /* = 0x%lx */", retval);
+	else
+		trace_seq_printf(s, " /* = %ld */", err_code);
 }
 
 #else
 
 #define __TRACE_GRAPH_PRINT_RETVAL 0
 
-#define print_graph_retval(_seq, _retval, _leaf, _func, _format) do {} while (0)
+#define print_graph_retval(_seq, _retval, _format) do {} while (0)
 
 #endif
 
@@ -741,16 +735,20 @@  print_graph_entry_leaf(struct trace_iterator *iter,
 	/* Function */
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
+	trace_seq_printf(s, "%ps", (void *)graph_ret->func);
+	if (flags & TRACE_GRAPH_ARGS)
+		print_function_args(s, &call->regs, graph_ret->func);
+	else
+		trace_seq_puts(s, "();");
 
 	/*
 	 * Write out the function return value if the option function-retval is
 	 * enabled.
 	 */
 	if (flags & __TRACE_GRAPH_PRINT_RETVAL)
-		print_graph_retval(s, graph_ret->retval, true, (void *)call->func,
-				!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
-	else
-		trace_seq_printf(s, "%ps();\n", (void *)call->func);
+		print_graph_retval(s, graph_ret->retval,
+				   !!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
+	trace_seq_printf(s, "\n");
 
 	print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
 			cpu, iter->ent->pid, flags);
@@ -788,7 +786,12 @@  print_graph_entry_nested(struct trace_iterator *iter,
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
-	trace_seq_printf(s, "%ps() {\n", (void *)call->func);
+	trace_seq_printf(s, "%ps", (void *)call->func);
+	if (flags & TRACE_GRAPH_ARGS)
+		print_function_args(s, &call->regs, call->func);
+	else
+		trace_seq_puts(s, "()");
+	trace_seq_printf(s, " {\n");
 
 	if (trace_seq_has_overflowed(s))
 		return TRACE_TYPE_PARTIAL_LINE;
@@ -1028,27 +1031,26 @@  print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
+	/*
+	 * If the return function does not have a matching entry,
+	 * then the entry was lost. Instead of just printing
+	 * the '}' and letting the user guess what function this
+	 * belongs to, write out the function name. Always do
+	 * that if the funcgraph-tail option is enabled.
+	 */
+	if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
+		trace_seq_puts(s, "}");
+	else
+		trace_seq_printf(s, "} /* %ps */", (void *)trace->func);
 	/*
 	 * Always write out the function name and its return value if the
 	 * function-retval option is enabled.
 	 */
 	if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
-		print_graph_retval(s, trace->retval, false, (void *)trace->func,
+		print_graph_retval(s, trace->retval,
 			!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
-	} else {
-		/*
-		 * If the return function does not have a matching entry,
-		 * then the entry was lost. Instead of just printing
-		 * the '}' and letting the user guess what function this
-		 * belongs to, write out the function name. Always do
-		 * that if the funcgraph-tail option is enabled.
-		 */
-		if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
-			trace_seq_puts(s, "}\n");
-		else
-			trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
 	}
-
+	trace_seq_printf(s, "\n");
 	/* Overrun */
 	if (flags & TRACE_GRAPH_PRINT_OVERRUN)
 		trace_seq_printf(s, " (Overruns: %u)\n",