Skip to content

Commit

Permalink
zinject: count matches and injections for each handler
Browse files Browse the repository at this point in the history 
When building tests with zinject, it can be quite difficult to work out
if you're producing the right kind of IO to match the rules you've set
up.

So, here we extend injection records to count the number of times a
handler matched the operation, and how often an error was actually
injected (ie after frequency and other exclusions are applied).

Then, display those counts in the `zinject` output.

Reviewed-by: Tony Hutter <[email protected]>
Reviewed-by: Alexander Motin <[email protected]>
Signed-off-by: Rob Norris <[email protected]>
Sponsored-by: Klara, Inc.
Sponsored-by: Wasabi Technology, Inc.
Closes #16938
  • Loading branch information
@robn
robn authored Jan 13, 2025
1 parent fae4c66 commit 2aa3fbe
Show file tree
Hide file tree
Showing 6 changed files with 236 additions and 39 deletions.
66 changes: 40 additions & 26 deletions cmd/zinject/zinject.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* Copyright (c) 2005, 2010, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2012, 2015 by Delphix. All rights reserved.
* Copyright (c) 2017, Intel Corporation.
* Copyright (c) 2023-2024, Klara Inc.
* Copyright (c) 2023-2025, Klara, Inc.
*/

/*
Expand Down Expand Up @@ -404,27 +404,30 @@ print_data_handler(int id, const char *pool, zinject_record_t *record,

if (*count == 0) {
(void) printf("%3s %-15s %-6s %-6s %-8s %3s %-4s "
"%-15s\n", "ID", "POOL", "OBJSET", "OBJECT", "TYPE",
"LVL", "DVAs", "RANGE");
"%-15s %-6s %-15s\n", "ID", "POOL", "OBJSET", "OBJECT",
"TYPE", "LVL", "DVAs", "RANGE", "MATCH", "INJECT");
(void) printf("--- --------------- ------ "
"------ -------- --- ---- ---------------\n");
"------ -------- --- ---- --------------- "
"------ ------\n");
}

*count += 1;

(void) printf("%3d %-15s %-6llu %-6llu %-8s %-3d 0x%02x ",
id, pool, (u_longlong_t)record->zi_objset,
(u_longlong_t)record->zi_object, type_to_name(record->zi_type),
record->zi_level, record->zi_dvas);


if (record->zi_start == 0 &&
record->zi_end == -1ULL)
(void) printf("all\n");
char rangebuf[32];
if (record->zi_start == 0 && record->zi_end == -1ULL)
snprintf(rangebuf, sizeof (rangebuf), "all");
else
(void) printf("[%llu, %llu]\n", (u_longlong_t)record->zi_start,
snprintf(rangebuf, sizeof (rangebuf), "[%llu, %llu]",
(u_longlong_t)record->zi_start,
(u_longlong_t)record->zi_end);


(void) printf("%3d %-15s %-6llu %-6llu %-8s %-3d 0x%02x %-15s "
"%6lu %6lu\n", id, pool, (u_longlong_t)record->zi_objset,
(u_longlong_t)record->zi_object, type_to_name(record->zi_type),
record->zi_level, record->zi_dvas, rangebuf,
record->zi_match_count, record->zi_inject_count);

return (0);
}

Expand All @@ -445,21 +448,25 @@ print_device_handler(int id, const char *pool, zinject_record_t *record,
return (0);

if (*count == 0) {
(void) printf("%3s %-15s %-16s %-5s %-10s %-9s\n",
"ID", "POOL", "GUID", "TYPE", "ERROR", "FREQ");
(void) printf("%3s %-15s %-16s %-5s %-10s %-9s "
"%-6s %-6s\n",
"ID", "POOL", "GUID", "TYPE", "ERROR", "FREQ",
"MATCH", "INJECT");
(void) printf(
"--- --------------- ---------------- "
"----- ---------- ---------\n");
"----- ---------- --------- "
"------ ------\n");
}

*count += 1;

double freq = record->zi_freq == 0 ? 100.0f :
(((double)record->zi_freq) / ZI_PERCENTAGE_MAX) * 100.0f;

(void) printf("%3d %-15s %llx %-5s %-10s %8.4f%%\n", id, pool,
(u_longlong_t)record->zi_guid, iotypestr[record->zi_iotype],
err_to_str(record->zi_error), freq);
(void) printf("%3d %-15s %llx %-5s %-10s %8.4f%% "
"%6lu %6lu\n", id, pool, (u_longlong_t)record->zi_guid,
iotypestr[record->zi_iotype], err_to_str(record->zi_error),
freq, record->zi_match_count, record->zi_inject_count);

return (0);
}
Expand All @@ -477,18 +484,25 @@ print_delay_handler(int id, const char *pool, zinject_record_t *record,
return (0);

if (*count == 0) {
(void) printf("%3s %-15s %-15s %-15s %s\n",
"ID", "POOL", "DELAY (ms)", "LANES", "GUID");
(void) printf("--- --------------- --------------- "
"--------------- ----------------\n");
(void) printf("%3s %-15s %-16s %-10s %-5s %-9s "
"%-6s %-6s\n",
"ID", "POOL", "GUID", "DELAY (ms)", "LANES", "FREQ",
"MATCH", "INJECT");
(void) printf("--- --------------- ---------------- "
"---------- ----- --------- "
"------ ------\n");
}

*count += 1;

(void) printf("%3d %-15s %-15llu %-15llu %llx\n", id, pool,
double freq = record->zi_freq == 0 ? 100.0f :
(((double)record->zi_freq) / ZI_PERCENTAGE_MAX) * 100.0f;

(void) printf("%3d %-15s %llx %10llu %5llu %8.4f%% "
"%6lu %6lu\n", id, pool, (u_longlong_t)record->zi_guid,
(u_longlong_t)NSEC2MSEC(record->zi_timer),
(u_longlong_t)record->zi_nlanes,
(u_longlong_t)record->zi_guid);
freq, record->zi_match_count, record->zi_inject_count);

return (0);
}
Expand Down
4 changes: 3 additions & 1 deletion include/sys/zfs_ioctl.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
* Copyright (c) 2012, 2024 by Delphix. All rights reserved.
* Copyright 2016 RackTop Systems.
* Copyright (c) 2017, Intel Corporation.
* Copyright (c) 2024, Klara, Inc.
* Copyright (c) 2024-2025, Klara, Inc.
*/

#ifndef _SYS_ZFS_IOCTL_H
Expand Down Expand Up @@ -421,6 +421,8 @@ typedef struct zinject_record {
uint64_t zi_nlanes;
uint32_t zi_cmd;
uint32_t zi_dvas;
uint64_t zi_match_count; /* count of times matched */
uint64_t zi_inject_count; /* count of times injected */
} zinject_record_t;

#define ZINJECT_NULL 0x1
Expand Down
60 changes: 49 additions & 11 deletions module/zfs/zio_inject.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
* Copyright (c) 2005, 2010, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2012, 2015 by Delphix. All rights reserved.
* Copyright (c) 2017, Intel Corporation.
* Copyright (c) 2024, Klara Inc.
* Copyright (c) 2024-2025, Klara, Inc.
*/

/*
Expand Down Expand Up @@ -129,6 +129,9 @@ static boolean_t
zio_match_handler(const zbookmark_phys_t *zb, uint64_t type, int dva,
zinject_record_t *record, int error)
{
boolean_t matched = B_FALSE;
boolean_t injected = B_FALSE;

/*
* Check for a match against the MOS, which is based on type
*/
Expand All @@ -137,9 +140,8 @@ zio_match_handler(const zbookmark_phys_t *zb, uint64_t type, int dva,
record->zi_object == DMU_META_DNODE_OBJECT) {
if (record->zi_type == DMU_OT_NONE ||
type == record->zi_type)
return (freq_triggered(record->zi_freq));
else
return (B_FALSE);
matched = B_TRUE;
goto done;
}

/*
Expand All @@ -153,10 +155,20 @@ zio_match_handler(const zbookmark_phys_t *zb, uint64_t type, int dva,
(record->zi_dvas == 0 ||
(dva != ZI_NO_DVA && (record->zi_dvas & (1ULL << dva)))) &&
error == record->zi_error) {
return (freq_triggered(record->zi_freq));
matched = B_TRUE;
goto done;
}

return (B_FALSE);
done:
if (matched) {
record->zi_match_count++;
injected = freq_triggered(record->zi_freq);
}

if (injected)
record->zi_inject_count++;

return (injected);
}

/*
Expand All @@ -177,8 +189,11 @@ zio_handle_panic_injection(spa_t *spa, const char *tag, uint64_t type)
continue;

if (handler->zi_record.zi_type == type &&
strcmp(tag, handler->zi_record.zi_func) == 0)
strcmp(tag, handler->zi_record.zi_func) == 0) {
handler->zi_record.zi_match_count++;
handler->zi_record.zi_inject_count++;
panic("Panic requested in function %s\n", tag);
}
}

rw_exit(&inject_lock);
Expand Down Expand Up @@ -336,6 +351,8 @@ zio_handle_label_injection(zio_t *zio, int error)

if (zio->io_vd->vdev_guid == handler->zi_record.zi_guid &&
(offset >= start && offset <= end)) {
handler->zi_record.zi_match_count++;
handler->zi_record.zi_inject_count++;
ret = error;
break;
}
Expand Down Expand Up @@ -400,12 +417,16 @@ zio_handle_device_injection_impl(vdev_t *vd, zio_t *zio, int err1, int err2)

if (handler->zi_record.zi_error == err1 ||
handler->zi_record.zi_error == err2) {
handler->zi_record.zi_match_count++;

/*
* limit error injection if requested
*/
if (!freq_triggered(handler->zi_record.zi_freq))
continue;

handler->zi_record.zi_inject_count++;

/*
* For a failed open, pretend like the device
* has gone away.
Expand Down Expand Up @@ -441,6 +462,8 @@ zio_handle_device_injection_impl(vdev_t *vd, zio_t *zio, int err1, int err2)
break;
}
if (handler->zi_record.zi_error == ENXIO) {
handler->zi_record.zi_match_count++;
handler->zi_record.zi_inject_count++;
ret = SET_ERROR(EIO);
break;
}
Expand Down Expand Up @@ -483,6 +506,8 @@ zio_handle_ignored_writes(zio_t *zio)
handler->zi_record.zi_cmd != ZINJECT_IGNORED_WRITES)
continue;

handler->zi_record.zi_match_count++;

/*
* Positive duration implies # of seconds, negative
* a number of txgs
Expand All @@ -495,8 +520,10 @@ zio_handle_ignored_writes(zio_t *zio)
}

/* Have a "problem" writing 60% of the time */
if (random_in_range(100) < 60)
if (random_in_range(100) < 60) {
handler->zi_record.zi_inject_count++;
zio->io_pipeline &= ~ZIO_VDEV_IO_STAGES;
}
break;
}

Expand All @@ -520,6 +547,9 @@ spa_handle_ignored_writes(spa_t *spa)
handler->zi_record.zi_cmd != ZINJECT_IGNORED_WRITES)
continue;

handler->zi_record.zi_match_count++;
handler->zi_record.zi_inject_count++;

if (handler->zi_record.zi_duration > 0) {
VERIFY(handler->zi_record.zi_timer == 0 ||
ddi_time_after64(
Expand Down Expand Up @@ -601,9 +631,6 @@ zio_handle_io_delay(zio_t *zio)
if (handler->zi_record.zi_cmd != ZINJECT_DELAY_IO)
continue;

if (!freq_triggered(handler->zi_record.zi_freq))
continue;

if (vd->vdev_guid != handler->zi_record.zi_guid)
continue;

Expand All @@ -628,6 +655,12 @@ zio_handle_io_delay(zio_t *zio)
ASSERT3U(handler->zi_record.zi_nlanes, >,
handler->zi_next_lane);

handler->zi_record.zi_match_count++;

/* Limit the use of this handler if requested */
if (!freq_triggered(handler->zi_record.zi_freq))
continue;

/*
* We want to issue this IO to the lane that will become
* idle the soonest, so we compare the soonest this
Expand Down Expand Up @@ -699,6 +732,9 @@ zio_handle_io_delay(zio_t *zio)
*/
min_handler->zi_next_lane = (min_handler->zi_next_lane + 1) %
min_handler->zi_record.zi_nlanes;

min_handler->zi_record.zi_inject_count++;

}

mutex_exit(&inject_delay_mtx);
Expand All @@ -721,9 +757,11 @@ zio_handle_pool_delay(spa_t *spa, hrtime_t elapsed, zinject_type_t command)
handler = list_next(&inject_handlers, handler)) {
ASSERT3P(handler->zi_spa_name, !=, NULL);
if (strcmp(spa_name(spa), handler->zi_spa_name) == 0) {
handler->zi_record.zi_match_count++;
uint64_t pause =
SEC2NSEC(handler->zi_record.zi_duration);
if (pause > elapsed) {
handler->zi_record.zi_inject_count++;
delay = pause - elapsed;
}
id = handler->zi_id;
Expand Down
2 changes: 1 addition & 1 deletion tests/runfiles/common.run
View file
Original file line number Diff line number Diff line change
Expand Up @@ -159,7 +159,7 @@ tests = ['json_sanity']
tags = ['functional', 'cli_root', 'json']

[tests/functional/cli_root/zinject]
tests = ['zinject_args']
tests = ['zinject_args', 'zinject_counts']
pre =
post =
tags = ['functional', 'cli_root', 'zinject']
Expand Down
1 change: 1 addition & 0 deletions tests/zfs-tests/tests/Makefile.am
View file
Original file line number Diff line number Diff line change
Expand Up @@ -615,6 +615,7 @@ nobase_dist_datadir_zfs_tests_tests_SCRIPTS += \
functional/cli_root/json/setup.ksh \
functional/cli_root/json/json_sanity.ksh \
functional/cli_root/zinject/zinject_args.ksh \
functional/cli_root/zinject/zinject_counts.ksh \
functional/cli_root/zdb/zdb_002_pos.ksh \
functional/cli_root/zdb/zdb_003_pos.ksh \
functional/cli_root/zdb/zdb_004_pos.ksh \
Expand Down
Loading

0 comments on commit 2aa3fbe

Please sign in to comment.