From 3a0f62449989930af876c72cf4d25613ddca3c0b Mon Sep 17 00:00:00 2001 From: Jim Harris Date: Wed, 10 Feb 2021 00:04:19 +0000 Subject: [PATCH] nvmf: add USDT probes for subsystem state changes Also add scripts/bpf/nvmf.bt to enable and log these probes. This patch also adds a script that can generate a bpftrace script snippet with string maps for needed enumerations (currently nvmf_tgt_state and spdk_nvmf_subsystem_state). This allows us to dynamically generate this from the source code, and can be extended for other enums we may want to add in the future. Thanks to Michal Berger for converting my original gen_enums.py script into gen_enums.sh! Signed-off-by: Jim Harris Signed-off-by: Michal Berger Change-Id: Iff34a6218aef40055ac14932eea5fc00e1c8bcf5 Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/7194 Community-CI: Mellanox Build Bot Tested-by: SPDK CI Jenkins Reviewed-by: Changpeng Liu Reviewed-by: Shuhei Matsumoto Reviewed-by: Konrad Sztyber --- lib/nvmf/subsystem.c | 14 +++++++ module/event/subsystems/nvmf/nvmf_tgt.c | 2 + scripts/bpf/gen_enums.sh | 52 +++++++++++++++++++++++++ scripts/bpf/nvmf.bt | 29 ++++++++++++++ scripts/bpftrace.sh | 8 +++- 5 files changed, 104 insertions(+), 1 deletion(-) create mode 100755 scripts/bpf/gen_enums.sh create mode 100644 scripts/bpf/nvmf.bt diff --git a/lib/nvmf/subsystem.c b/lib/nvmf/subsystem.c index 6f3b1f483..0034c7614 100644 --- a/lib/nvmf/subsystem.c +++ b/lib/nvmf/subsystem.c @@ -48,6 +48,7 @@ #include "spdk/bdev_module.h" #include "spdk/log.h" #include "spdk_internal/utf.h" +#include "spdk_internal/usdt.h" #define MODEL_NUMBER_DEFAULT "SPDK bdev Controller" #define NVMF_SUBSYSTEM_DEFAULT_NAMESPACES 32 @@ -508,6 +509,9 @@ subsystem_state_change_done(struct spdk_io_channel_iter *i, int status) struct subsystem_state_change_ctx *ctx = spdk_io_channel_iter_get_ctx(i); enum spdk_nvmf_subsystem_state intermediate_state; + SPDK_DTRACE_PROBE4(nvmf_subsystem_change_state_done, ctx->subsystem->subnqn, + ctx->requested_state, ctx->original_state, status); + if (status == 0) { status = nvmf_subsystem_set_state(ctx->subsystem, ctx->requested_state); if (status) { @@ -543,6 +547,12 @@ static void subsystem_state_change_continue(void *ctx, int status) { struct spdk_io_channel_iter *i = ctx; + struct subsystem_state_change_ctx *_ctx __attribute__((unused)); + + _ctx = spdk_io_channel_iter_get_ctx(i); + SPDK_DTRACE_PROBE3(nvmf_pg_change_state_done, _ctx->subsystem->subnqn, + _ctx->requested_state, spdk_thread_get_id(spdk_get_thread())); + spdk_for_each_channel_continue(i, status); } @@ -557,6 +567,8 @@ subsystem_state_change_on_pg(struct spdk_io_channel_iter *i) ch = spdk_io_channel_iter_get_channel(i); group = spdk_io_channel_get_ctx(ch); + SPDK_DTRACE_PROBE3(nvmf_pg_change_state, ctx->subsystem->subnqn, + ctx->requested_state, spdk_thread_get_id(spdk_get_thread())); switch (ctx->requested_state) { case SPDK_NVMF_SUBSYSTEM_INACTIVE: nvmf_poll_group_remove_subsystem(group, ctx->subsystem, subsystem_state_change_continue, i); @@ -593,6 +605,8 @@ nvmf_subsystem_state_change(struct spdk_nvmf_subsystem *subsystem, return -EBUSY; } + SPDK_DTRACE_PROBE3(nvmf_subsystem_change_state, subsystem->subnqn, + requested_state, subsystem->state); /* If we are already in the requested state, just call the callback immediately. */ if (subsystem->state == requested_state) { subsystem->changing_state = false; diff --git a/module/event/subsystems/nvmf/nvmf_tgt.c b/module/event/subsystems/nvmf/nvmf_tgt.c index 4df1f3060..00797386a 100644 --- a/module/event/subsystems/nvmf/nvmf_tgt.c +++ b/module/event/subsystems/nvmf/nvmf_tgt.c @@ -38,6 +38,7 @@ #include "spdk/log.h" #include "spdk/nvme.h" #include "spdk/nvmf_cmd.h" +#include "spdk_internal/usdt.h" enum nvmf_tgt_state { NVMF_TGT_INIT_NONE = 0, @@ -378,6 +379,7 @@ nvmf_tgt_advance_state(void) int ret; do { + SPDK_DTRACE_PROBE1(nvmf_tgt_state, g_tgt_state); prev_state = g_tgt_state; switch (g_tgt_state) { diff --git a/scripts/bpf/gen_enums.sh b/scripts/bpf/gen_enums.sh new file mode 100755 index 000000000..33fdaf5e7 --- /dev/null +++ b/scripts/bpf/gen_enums.sh @@ -0,0 +1,52 @@ +#!/usr/bin/env bash +set -e + +rootdir=$(git rev-parse --show-toplevel) + +_print_enums() { + local enum_type=$1 enum_string=$2 enum_prefix=$3 enum output + + output=$(< "$rootdir/$(git -C "$rootdir" grep -l "$enum_string" -- lib module)") + + # Isolate the enum block + output=${output#*$enum_string$'\n'} output=${output%%$'\n'\};*} + # Fold it onto an array + IFS="," read -ra output <<< "${output//[[:space:]]/}" + # Drop the assignments + output=("${output[@]/=*/}") + + for enum in "${!output[@]}"; do + if [[ ${output[enum]} != "$enum_prefix"* ]]; then + printf 'enum name %s does not start with expected prefix %s\n' "${output[enum]}" "$enum_prefix" + return 1 + fi >&2 + printf ' @%s[%d] = "%s";\n' "$enum_type" "$enum" "${output[enum]#$enum_prefix}" + done +} + +print_enums() { + for state in "${!state_enums[@]}"; do + _print_enums "$state" "${state_enums["$state"]}" "${state_prefix["$state"]}" + done +} + +print_clear() { printf ' clear(@%s);\n' "${!state_enums[@]}"; } + +declare -A state_enums=() state_prefix=() + +state_enums["target"]="enum nvmf_tgt_state {" +state_enums["subsystem"]="enum spdk_nvmf_subsystem_state {" +state_prefix["target"]=NVMF_TGT_ +state_prefix["subsystem"]=SPDK_NVMF_SUBSYSTEM_ + +enums=$(print_enums) +clear=$(print_clear) + +cat <<- ENUM + BEGIN { + $enums + } + END { + $clear + } +ENUM diff --git a/scripts/bpf/nvmf.bt b/scripts/bpf/nvmf.bt new file mode 100644 index 000000000..b9322f07e --- /dev/null +++ b/scripts/bpf/nvmf.bt @@ -0,0 +1,29 @@ +usdt:__EXE__:nvmf_tgt_state { + printf("%d.%06d: nvmf_tgt reached state %s\n", + elapsed / (uint64)(1000 * 1000), elapsed % (uint64)(1000 * 1000), + @target[arg0]); +} + +usdt:__EXE__:nvmf_subsystem_change_state { + printf("%d.%06d: %s change state from %s to %s start\n", + elapsed / (uint64)(1000 * 1000), elapsed % (uint64)(1000 * 1000), + str(arg0), @subsystem[arg2], @subsystem[arg1]); +} + +usdt:__EXE__:nvmf_subsystem_change_state_done { + printf("%d.%06d: %s change state from %s to %s %s\n", + elapsed / (uint64)(1000 * 1000), elapsed % (uint64)(1000 * 1000), + str(arg0), @subsystem[arg2], @subsystem[arg1], arg3 ? "failed" : "done"); +} + +usdt:__EXE__:nvmf_pg_change_state { + printf("%d.%06d: %s on thread %d state to %s start\n", + elapsed / (uint64)(1000 * 1000), elapsed % (uint64)(1000 * 1000), + str(arg0), arg2, @subsystem[arg1]); +} + +usdt:__EXE__:nvmf_pg_change_state_done { + printf("%d.%06d: %s on thread %d state to %s done\n", + elapsed / (uint64)(1000 * 1000), elapsed % (uint64)(1000 * 1000), + str(arg0), arg2, @subsystem[arg1]); +} diff --git a/scripts/bpftrace.sh b/scripts/bpftrace.sh index d35714b15..6a2afbb85 100755 --- a/scripts/bpftrace.sh +++ b/scripts/bpftrace.sh @@ -1,9 +1,15 @@ #!/usr/bin/env bash +set -e + if [ $# -lt 2 ]; then echo "usage: $0