Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Extend import_progress kstat with a notes field #15539

Merged
merged 1 commit into from
Dec 5, 2023
Merged

Extend import_progress kstat with a notes field #15539

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions include/sys/spa.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -971,6 +971,10 @@ extern int spa_import_progress_set_max_txg(uint64_t pool_guid,
uint64_t max_txg);
extern int spa_import_progress_set_state(uint64_t pool_guid,
spa_load_state_t spa_load_state);
extern void spa_import_progress_set_notes(spa_t *spa,
const char *fmt, ...) __printflike(2, 3);
extern void spa_import_progress_set_notes_nolog(spa_t *spa,
const char *fmt, ...) __printflike(2, 3);

/* Pool configuration locks */
extern int spa_config_tryenter(spa_t *spa, int locks, const void *tag,
Expand Down
41 changes: 39 additions & 2 deletions module/zfs/spa.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3109,6 +3109,7 @@ spa_load(spa_t *spa, spa_load_state_t state, spa_import_type_t type)
spa->spa_load_state = state;
(void) spa_import_progress_set_state(spa_guid(spa),
spa_load_state(spa));
spa_import_progress_set_notes(spa, "spa_load()");

gethrestime(&spa->spa_loaded_ts);
error = spa_load_impl(spa, type, &ereport);
Expand Down Expand Up @@ -3337,7 +3338,7 @@ spa_activity_check(spa_t *spa, uberblock_t *ub, nvlist_t *config)
uint64_t mmp_config = ub->ub_mmp_config;
uint16_t mmp_seq = MMP_SEQ_VALID(ub) ? MMP_SEQ(ub) : 0;
uint64_t import_delay;
hrtime_t import_expire;
hrtime_t import_expire, now;
nvlist_t *mmp_label = NULL;
vdev_t *rvd = spa->spa_root_vdev;
kcondvar_t cv;
Expand Down Expand Up @@ -3375,7 +3376,17 @@ spa_activity_check(spa_t *spa, uberblock_t *ub, nvlist_t *config)

import_expire = gethrtime() + import_delay;

while (gethrtime() < import_expire) {
spa_import_progress_set_notes(spa, "Checking MMP activity, waiting "
"%llu ms", (u_longlong_t)NSEC2MSEC(import_delay));

int interations = 0;
while ((now = gethrtime()) < import_expire) {
if (interations++ % 30 == 0) {
spa_import_progress_set_notes(spa, "Checking MMP "
"activity, %llu ms remaining",
(u_longlong_t)NSEC2MSEC(import_expire - now));
}

(void) spa_import_progress_set_mmp_check(spa_guid(spa),
NSEC2SEC(import_expire - gethrtime()));

Expand Down Expand Up @@ -4995,6 +5006,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
/*
* Retrieve the checkpoint txg if the pool has a checkpoint.
*/
spa_import_progress_set_notes(spa, "Loading checkpoint txg");
error = spa_ld_read_checkpoint_txg(spa);
if (error != 0)
return (error);
Expand All @@ -5007,6 +5019,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* initiated. Otherwise we could be reading from indirect vdevs before
* we have loaded their mappings.
*/
spa_import_progress_set_notes(spa, "Loading indirect vdev metadata");
error = spa_ld_open_indirect_vdev_metadata(spa);
if (error != 0)
return (error);
Expand All @@ -5015,6 +5028,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Retrieve the full list of active features from the MOS and check if
* they are all supported.
*/
spa_import_progress_set_notes(spa, "Checking feature flags");
error = spa_ld_check_features(spa, &missing_feat_write);
if (error != 0)
return (error);
Expand All @@ -5023,13 +5037,15 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Load several special directories from the MOS needed by the dsl_pool
* layer.
*/
spa_import_progress_set_notes(spa, "Loading special MOS directories");
error = spa_ld_load_special_directories(spa);
if (error != 0)
return (error);

/*
* Retrieve pool properties from the MOS.
*/
spa_import_progress_set_notes(spa, "Loading properties");
error = spa_ld_get_props(spa);
if (error != 0)
return (error);
Expand All @@ -5038,6 +5054,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Retrieve the list of auxiliary devices - cache devices and spares -
* and open them.
*/
spa_import_progress_set_notes(spa, "Loading AUX vdevs");
error = spa_ld_open_aux_vdevs(spa, type);
if (error != 0)
return (error);
Expand All @@ -5046,14 +5063,17 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Load the metadata for all vdevs. Also check if unopenable devices
* should be autoreplaced.
*/
spa_import_progress_set_notes(spa, "Loading vdev metadata");
error = spa_ld_load_vdev_metadata(spa);
if (error != 0)
return (error);

spa_import_progress_set_notes(spa, "Loading dedup tables");
error = spa_ld_load_dedup_tables(spa);
if (error != 0)
return (error);

spa_import_progress_set_notes(spa, "Loading BRT");
error = spa_ld_load_brt(spa);
if (error != 0)
return (error);
Expand All @@ -5062,6 +5082,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Verify the logs now to make sure we don't have any unexpected errors
* when we claim log blocks later.
*/
spa_import_progress_set_notes(spa, "Verifying Log Devices");
error = spa_ld_verify_logs(spa, type, ereport);
if (error != 0)
return (error);
Expand All @@ -5083,6 +5104,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* state. When performing an extreme rewind, we verify the whole pool,
* which can take a very long time.
*/
spa_import_progress_set_notes(spa, "Verifying pool data");
error = spa_ld_verify_pool_data(spa);
if (error != 0)
return (error);
Expand All @@ -5092,13 +5114,15 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* we write anything to the pool because we'd need to update the space
* accounting using the deflated sizes.
*/
spa_import_progress_set_notes(spa, "Calculating deflated space");
spa_update_dspace(spa);

/*
* We have now retrieved all the information we needed to open the
* pool. If we are importing the pool in read-write mode, a few
* additional steps must be performed to finish the import.
*/
spa_import_progress_set_notes(spa, "Starting import");
if (spa_writeable(spa) && (spa->spa_load_state == SPA_LOAD_RECOVER ||
spa->spa_load_max_txg == UINT64_MAX)) {
uint64_t config_cache_txg = spa->spa_config_txg;
Expand All @@ -5122,6 +5146,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
(u_longlong_t)spa->spa_uberblock.ub_checkpoint_txg);
}

spa_import_progress_set_notes(spa, "Claiming ZIL blocks");
/*
* Traverse the ZIL and claim all blocks.
*/
Expand All @@ -5141,13 +5166,15 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* will have been set for us by ZIL traversal operations
* performed above.
*/
spa_import_progress_set_notes(spa, "Syncing ZIL claims");
txg_wait_synced(spa->spa_dsl_pool, spa->spa_claim_max_txg);

/*
* Check if we need to request an update of the config. On the
* next sync, we would update the config stored in vdev labels
* and the cachefile (by default /etc/zfs/zpool.cache).
*/
spa_import_progress_set_notes(spa, "Updating configs");
spa_ld_check_for_config_update(spa, config_cache_txg,
update_config_cache);

Expand All @@ -5156,6 +5183,7 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* Then check all DTLs to see if anything needs resilvering.
* The resilver will be deferred if a rebuild was started.
*/
spa_import_progress_set_notes(spa, "Starting resilvers");
if (vdev_rebuild_active(spa->spa_root_vdev)) {
vdev_rebuild_restart(spa);
} else if (!dsl_scan_resilvering(spa->spa_dsl_pool) &&
Expand All @@ -5169,6 +5197,8 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
*/
spa_history_log_version(spa, "open", NULL);

spa_import_progress_set_notes(spa,
"Restarting device removals");
spa_restart_removal(spa);
spa_spawn_aux_threads(spa);

Expand All @@ -5181,19 +5211,26 @@ spa_load_impl(spa_t *spa, spa_import_type_t type, const char **ereport)
* auxiliary threads above (from which the livelist
* deletion zthr is part of).
*/
spa_import_progress_set_notes(spa,
"Cleaning up inconsistent objsets");
(void) dmu_objset_find(spa_name(spa),
dsl_destroy_inconsistent, NULL, DS_FIND_CHILDREN);

/*
* Clean up any stale temporary dataset userrefs.
*/
spa_import_progress_set_notes(spa,
"Cleaning up temporary userrefs");
dsl_pool_clean_tmp_userrefs(spa->spa_dsl_pool);

spa_config_enter(spa, SCL_CONFIG, FTAG, RW_READER);
spa_import_progress_set_notes(spa, "Restarting initialize");
vdev_initialize_restart(spa->spa_root_vdev);
spa_import_progress_set_notes(spa, "Restarting TRIM");
vdev_trim_restart(spa->spa_root_vdev);
vdev_autotrim_restart(spa);
spa_config_exit(spa, SCL_CONFIG, FTAG);
spa_import_progress_set_notes(spa, "Finished importing");
}

spa_import_progress_remove(spa_guid(spa));
Expand Down
12 changes: 9 additions & 3 deletions module/zfs/spa_log_spacemap.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1153,6 +1153,7 @@ spa_ld_log_sm_data(spa_t *spa)

uint_t pn = 0;
uint64_t ps = 0;
uint64_t nsm = 0;
psls = sls = avl_first(&spa->spa_sm_logs_by_txg);
while (sls != NULL) {
/* Prefetch log spacemaps up to 16 TXGs or MBs ahead. */
Expand Down Expand Up @@ -1185,6 +1186,10 @@ spa_ld_log_sm_data(spa_t *spa)
summary_add_data(spa, sls->sls_txg,
sls->sls_mscount, 0, sls->sls_nblocks);

spa_import_progress_set_notes_nolog(spa,
"Read %llu of %lu log space maps", (u_longlong_t)nsm,
avl_numnodes(&spa->spa_sm_logs_by_txg));

struct spa_ld_log_sm_arg vla = {
.slls_spa = spa,
.slls_txg = sls->sls_txg
Expand All @@ -1200,6 +1205,7 @@ spa_ld_log_sm_data(spa_t *spa)

pn--;
ps -= space_map_length(sls->sls_sm);
nsm++;
space_map_close(sls->sls_sm);
sls->sls_sm = NULL;
sls = AVL_NEXT(&spa->spa_sm_logs_by_txg, sls);
Expand All @@ -1210,11 +1216,11 @@ spa_ld_log_sm_data(spa_t *spa)

hrtime_t read_logs_endtime = gethrtime();
spa_load_note(spa,
"read %llu log space maps (%llu total blocks - blksz = %llu bytes) "
"in %lld ms", (u_longlong_t)avl_numnodes(&spa->spa_sm_logs_by_txg),
"Read %lu log space maps (%llu total blocks - blksz = %llu bytes) "
"in %lld ms", avl_numnodes(&spa->spa_sm_logs_by_txg),
(u_longlong_t)spa_log_sm_nblocks(spa),
(u_longlong_t)zfs_log_sm_blksz,
(longlong_t)((read_logs_endtime - read_logs_starttime) / 1000000));
(longlong_t)NSEC2MSEC(read_logs_endtime - read_logs_starttime));

out:
if (error != 0) {
Expand Down
74 changes: 70 additions & 4 deletions module/zfs/spa_misc.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -426,6 +426,8 @@ spa_load_note(spa_t *spa, const char *fmt, ...)

zfs_dbgmsg("spa_load(%s, config %s): %s", spa->spa_name,
spa->spa_trust_config ? "trusted" : "untrusted", buf);

spa_import_progress_set_notes_nolog(spa, "%s", buf);
}

/*
Expand Down Expand Up @@ -2184,6 +2186,7 @@ typedef struct spa_import_progress {
uint64_t pool_guid; /* unique id for updates */
char *pool_name;
spa_load_state_t spa_load_state;
char *spa_load_notes;
uint64_t mmp_sec_remaining; /* MMP activity check */
uint64_t spa_load_max_txg; /* rewind txg */
procfs_list_node_t smh_node;
Expand All @@ -2194,9 +2197,9 @@ spa_history_list_t *spa_import_progress_list = NULL;
static int
spa_import_progress_show_header(struct seq_file *f)
{
seq_printf(f, "%-20s %-14s %-14s %-12s %s\n", "pool_guid",
seq_printf(f, "%-20s %-14s %-14s %-12s %-16s %s\n", "pool_guid",
"load_state", "multihost_secs", "max_txg",
"pool_name");
"pool_name", "notes");
return (0);
}

Expand All @@ -2205,11 +2208,12 @@ spa_import_progress_show(struct seq_file *f, void *data)
{
spa_import_progress_t *sip = (spa_import_progress_t *)data;

seq_printf(f, "%-20llu %-14llu %-14llu %-12llu %s\n",
seq_printf(f, "%-20llu %-14llu %-14llu %-12llu %-16s %s\n",
(u_longlong_t)sip->pool_guid, (u_longlong_t)sip->spa_load_state,
(u_longlong_t)sip->mmp_sec_remaining,
(u_longlong_t)sip->spa_load_max_txg,
(sip->pool_name ? sip->pool_name : "-"));
(sip->pool_name ? sip->pool_name : "-"),
(sip->spa_load_notes ? sip->spa_load_notes : "-"));

return (0);
}
Expand All @@ -2223,6 +2227,8 @@ spa_import_progress_truncate(spa_history_list_t *shl, unsigned int size)
sip = list_remove_head(&shl->procfs_list.pl_list);
if (sip->pool_name)
spa_strfree(sip->pool_name);
if (sip->spa_load_notes)
kmem_strfree(sip->spa_load_notes);
kmem_free(sip, sizeof (spa_import_progress_t));
shl->size--;
}
Expand Down Expand Up @@ -2278,6 +2284,10 @@ spa_import_progress_set_state(uint64_t pool_guid,
sip = list_prev(&shl->procfs_list.pl_list, sip)) {
if (sip->pool_guid == pool_guid) {
sip->spa_load_state = load_state;
if (sip->spa_load_notes != NULL) {
kmem_strfree(sip->spa_load_notes);
sip->spa_load_notes = NULL;
}
error = 0;
break;
}
Expand All @@ -2287,6 +2297,59 @@ spa_import_progress_set_state(uint64_t pool_guid,
return (error);
}

static void
spa_import_progress_set_notes_impl(spa_t *spa, boolean_t log_dbgmsg,
const char *fmt, va_list adx)
{
spa_history_list_t *shl = spa_import_progress_list;
spa_import_progress_t *sip;
uint64_t pool_guid = spa_guid(spa);

if (shl->size == 0)
return;

char *notes = kmem_vasprintf(fmt, adx);

mutex_enter(&shl->procfs_list.pl_lock);
for (sip = list_tail(&shl->procfs_list.pl_list); sip != NULL;
sip = list_prev(&shl->procfs_list.pl_list, sip)) {
if (sip->pool_guid == pool_guid) {
if (sip->spa_load_notes != NULL) {
kmem_strfree(sip->spa_load_notes);
sip->spa_load_notes = NULL;
}
sip->spa_load_notes = notes;
if (log_dbgmsg)
zfs_dbgmsg("'%s' %s", sip->pool_name, notes);
notes = NULL;
break;
}
}
mutex_exit(&shl->procfs_list.pl_lock);
if (notes != NULL)
kmem_strfree(notes);
}

void
spa_import_progress_set_notes(spa_t *spa, const char *fmt, ...)
{
va_list adx;

va_start(adx, fmt);
spa_import_progress_set_notes_impl(spa, B_TRUE, fmt, adx);
va_end(adx);
}

void
spa_import_progress_set_notes_nolog(spa_t *spa, const char *fmt, ...)
{
va_list adx;

va_start(adx, fmt);
spa_import_progress_set_notes_impl(spa, B_FALSE, fmt, adx);
va_end(adx);
}

int
spa_import_progress_set_max_txg(uint64_t pool_guid, uint64_t load_max_txg)
{
Expand Down Expand Up @@ -2355,6 +2418,7 @@ spa_import_progress_add(spa_t *spa)
poolname = spa_name(spa);
sip->pool_name = spa_strdup(poolname);
sip->spa_load_state = spa_load_state(spa);
sip->spa_load_notes = NULL;

mutex_enter(&shl->procfs_list.pl_lock);
procfs_list_add(&shl->procfs_list, sip);
Expand All @@ -2374,6 +2438,8 @@ spa_import_progress_remove(uint64_t pool_guid)
if (sip->pool_guid == pool_guid) {
if (sip->pool_name)
spa_strfree(sip->pool_name);
if (sip->spa_load_notes)
spa_strfree(sip->spa_load_notes);
list_remove(&shl->procfs_list.pl_list, sip);
shl->size--;
kmem_free(sip, sizeof (spa_import_progress_t));
Expand Down
Loading
Loading