如何使用 ftrace 来 function_trace 内核模块中断？

Question

我有一个带有 2 个内核 (1.2 GHz) 的 Banana Pi Arm 设备，运行 Debian 内核，并启用了 ftrace 内核调试选项。我想确定内核模块函数所花费的时间量。该函数的形式为

static irq_handler_t vtgpio_irq_handler(unsigned int irq, void *dev_id, struct pt_regs *regs);

加载模块后，在我的调试文件系统中，我看到名称作为过滤器公开。我正在跟踪所有功能。我尝试启用这些trace_printk语句，但看不到它打印在我的跟踪文件中。下面是该函数的实现：

/** @brief handler for rising signal */
static irq_handler_t vtgpio_irq_handler(unsigned int irq, void *dev_id, struct pt_regs *regs) {
  trace_printk(KERN_INFO "rise\n");
  pause();
  return (irq_handler_t) IRQ_HANDLED; // return that we all good                                                                                                                               
}

我知道该函数正在被调用，因为我看到if I replacement withprintk中的语句。我还知道一些模块函数是可追踪的，例如写入 sysfs 存储函数。例如我可以看到dmesg | tailtrace_printkprintk

static struct kobj_attribute mode_attr = __ATTR(mode, 0660, mode_show, mode_store);

从写入到 的 ftrace mode_store。

1)               |  sys_write() {
1)   0.708 us    |    fget_light();
1)               |    vfs_write() {
1)   0.875 us    |      rw_verify_area();
1)               |      sysfs_write_file() {
1)   0.459 us    |        mutex_lock();
1)               |        get_zeroed_page() {
1)               |          __get_free_pages() {
1)               |            __alloc_pages_nodemask() {
1)   0.708 us    |              next_zones_zonelist();
1)               |              get_page_from_freelist() {
1)   0.458 us    |                next_zones_zonelist();
1)   1.000 us    |                __zone_watermark_ok();
1)               |                kmap_atomic() {
1)   0.625 us    |                  add_preempt_count();
1)   0.625 us    |                  page_address();
1)   9.250 us    |                }
1)               |                __kunmap_atomic() {
1)   0.750 us    |                  sub_preempt_count();
1)   5.459 us    |                }
1) + 41.000 us   |              }
1) + 53.209 us   |            }
1)   0.542 us    |            page_address();
1) + 62.541 us   |          }
1) + 66.958 us   |        }
1)   0.917 us    |        sysfs_get_active();
1)               |        mode_store() {
1)               |          /* <6>VT-GPIO_TEST: resume */
1)               |          gpio_direction_output() {
1)               |            _raw_spin_lock_irqsave() {
1)               |              __raw_spin_lock_irqsave() {
1)   0.834 us    |                add_preempt_count();
1)   5.375 us    |              }
1)   9.458 us    |            }
1)   0.834 us    |            gpio_ensure_requested();
1)               |            _raw_spin_unlock_irqrestore() {
1)   0.708 us    |              sub_preempt_count();
1)   5.125 us    |            }
1)               |            sunxi_gpio_direction_out() {
1)   1.125 us    |              gpio_set_one_pin_io_status();
1)   1.167 us    |              gpio_write_one_pin_value();
1) + 12.333 us   |            }
1) + 47.250 us   |          }
1)               |          gpio_direction_input() {
1)               |            _raw_spin_lock_irqsave() {
1)               |              __raw_spin_lock_irqsave() {
1)   0.625 us    |                add_preempt_count();
1)   5.167 us    |              }
1)   9.667 us    |            }
1)   0.583 us    |            gpio_ensure_requested();
1)               |            _raw_spin_unlock_irqrestore() {
1)   0.708 us    |              sub_preempt_count();
1)   5.166 us    |            }
1)               |            sunxi_gpio_direction_in() {
1)   0.667 us    |              gpio_set_one_pin_io_status();
1)   5.208 us    |            }
1) + 38.833 us   |          }
1) ! 105.833 us  |        }
1)   0.875 us    |        sysfs_put_active();
1)   0.875 us    |        mutex_unlock();
1) ! 204.500 us  |      }
1)   0.416 us    |      __fsnotify_parent();
1)               |      fsnotify() {
1)               |        __srcu_read_lock() {
1)   0.583 us    |          add_preempt_count();
1)   0.667 us    |          sub_preempt_count();
1)   9.542 us    |        }
1)               |        __srcu_read_unlock() {
1)   0.584 us    |          add_preempt_count();
1)   0.667 us    |          sub_preempt_count();
1)   9.041 us    |        }
1) + 30.125 us   |      }
1) ! 252.708 us  |    }
1) ! 262.292 us  |  }

在mode_store此跟踪中，实际上将高电平或低电平写入 IRQ 处理程序注册的引脚。任何提示都会非常有帮助，我正在尝试测量 IRQ 处理程序的开销。