1
0
mirror of git://sourceware.org/git/lvm2.git synced 2024-12-21 13:34:40 +03:00

logging: classify log_debug messages

Place most log_debug() messages into a class.
This commit is contained in:
Alasdair G Kergon 2013-01-07 22:30:29 +00:00
parent 7f747a0d73
commit 06abb2dd4c
47 changed files with 571 additions and 570 deletions

View File

@ -491,7 +491,7 @@ int target_version(const char *target_name, uint32_t *maj,
goto_out;
if (!dm_task_run(dmt)) {
log_debug("Failed to get %s target version", target_name);
log_debug_activation("Failed to get %s target version", target_name);
/* Assume this was because LIST_VERSIONS isn't supported */
*maj = 0;
*min = 0;
@ -698,7 +698,7 @@ int lv_check_transient(struct logical_volume *lv)
if (!activation())
return 0;
log_debug("Checking transient status for LV %s/%s", lv->vg->name, lv->name);
log_debug_activation("Checking transient status for LV %s/%s", lv->vg->name, lv->name);
if (!(dm = dev_manager_create(lv->vg->cmd, lv->vg->name, 1)))
return_0;
@ -722,7 +722,7 @@ int lv_snapshot_percent(const struct logical_volume *lv, percent_t *percent)
if (!activation())
return 0;
log_debug("Checking snapshot percent for LV %s/%s", lv->vg->name, lv->name);
log_debug_activation("Checking snapshot percent for LV %s/%s", lv->vg->name, lv->name);
if (!(dm = dev_manager_create(lv->vg->cmd, lv->vg->name, 1)))
return_0;
@ -753,7 +753,7 @@ int lv_mirror_percent(struct cmd_context *cmd, const struct logical_volume *lv,
if (!activation())
return 0;
log_debug("Checking mirror percent for LV %s/%s", lv->vg->name, lv->name);
log_debug_activation("Checking mirror percent for LV %s/%s", lv->vg->name, lv->name);
if (!lv_info(cmd, lv, 0, &info, 0, 0))
return_0;
@ -790,8 +790,8 @@ int lv_thin_pool_percent(const struct logical_volume *lv, int metadata,
if (!activation())
return 0;
log_debug("Checking thin %sdata percent for LV %s/%s",
(metadata) ? "meta" : "", lv->vg->name, lv->name);
log_debug_activation("Checking thin %sdata percent for LV %s/%s",
(metadata) ? "meta" : "", lv->vg->name, lv->name);
if (!(dm = dev_manager_create(lv->vg->cmd, lv->vg->name, 1)))
return_0;
@ -816,8 +816,8 @@ int lv_thin_percent(const struct logical_volume *lv,
if (!activation())
return 0;
log_debug("Checking thin percent for LV %s/%s",
lv->vg->name, lv->name);
log_debug_activation("Checking thin percent for LV %s/%s",
lv->vg->name, lv->name);
if (!(dm = dev_manager_create(lv->vg->cmd, lv->vg->name, 1)))
return_0;
@ -843,8 +843,8 @@ int lv_thin_pool_transaction_id(const struct logical_volume *lv,
if (!activation())
return 0;
log_debug("Checking thin percent for LV %s/%s",
lv->vg->name, lv->name);
log_debug_activation("Checking thin percent for LV %s/%s",
lv->vg->name, lv->name);
if (!(dm = dev_manager_create(lv->vg->cmd, lv->vg->name, 1)))
return_0;
@ -973,7 +973,7 @@ int lvs_in_vg_activated(const struct volume_group *vg)
if (lv_is_visible(lvl->lv))
count += (_lv_active(vg->cmd, lvl->lv) == 1);
log_debug("Counted %d active LVs in VG %s", count, vg->name);
log_debug_activation("Counted %d active LVs in VG %s", count, vg->name);
return count;
}
@ -990,7 +990,7 @@ int lvs_in_vg_opened(const struct volume_group *vg)
if (lv_is_visible(lvl->lv))
count += (_lv_open_count(vg->cmd, lvl->lv) > 0);
log_debug("Counted %d open LVs in VG %s", count, vg->name);
log_debug_activation("Counted %d open LVs in VG %s", count, vg->name);
return count;
}
@ -1265,8 +1265,8 @@ int monitor_dev_for_events(struct cmd_context *cmd, struct logical_volume *lv,
*/
if (laopts->skip_in_use && lv_info(lv->vg->cmd, lv, 1, &info, 1, 0) &&
(info.open_count != 1)) {
log_debug("Skipping unmonitor of opened %s (open:%d)",
lv->name, info.open_count);
log_debug_activation("Skipping unmonitor of opened %s (open:%d)",
lv->name, info.open_count);
return 1;
}
@ -1633,10 +1633,10 @@ static int _lv_resume(struct cmd_context *cmd, const char *lvid_s,
goto out;
}
log_debug("Resuming LV %s/%s%s%s%s.", lv->vg->name, lv->name,
error_if_not_active ? "" : " if active",
laopts->origin_only ? " without snapshots" : "",
laopts->revert ? " (reverting)" : "");
log_debug_activation("Resuming LV %s/%s%s%s%s.", lv->vg->name, lv->name,
error_if_not_active ? "" : " if active",
laopts->origin_only ? " without snapshots" : "",
laopts->revert ? " (reverting)" : "");
if (!lv_info(cmd, lv, laopts->origin_only, &info, 0, 0))
goto_out;
@ -1739,7 +1739,7 @@ int lv_deactivate(struct cmd_context *cmd, const char *lvid_s)
goto out;
}
log_debug("Deactivating %s/%s.", lv->vg->name, lv->name);
log_debug_activation("Deactivating %s/%s.", lv->vg->name, lv->name);
if (!lv_info(cmd, lv, 0, &info, 1, 0))
goto_out;
@ -1849,9 +1849,9 @@ static int _lv_activate(struct cmd_context *cmd, const char *lvid_s,
if (filter)
laopts->read_only = _passes_readonly_filter(cmd, lv);
log_debug("Activating %s/%s%s%s.", lv->vg->name, lv->name,
laopts->exclusive ? " exclusively" : "",
laopts->read_only ? " read-only" : "");
log_debug_activation("Activating %s/%s%s%s.", lv->vg->name, lv->name,
laopts->exclusive ? " exclusively" : "",
laopts->read_only ? " read-only" : "");
if (!lv_info(cmd, lv, 0, &info, 0, 0))
goto_out;

View File

@ -252,15 +252,15 @@ static int _ignore_blocked_mirror_devices(struct device *dev,
for (i = 0; images_health[i]; i++)
if (images_health[i] != 'A') {
log_debug("%s: Mirror image %d marked as failed",
dev_name(dev), i);
log_debug_activation("%s: Mirror image %d marked as failed",
dev_name(dev), i);
check_for_blocking = 1;
}
if (!check_for_blocking && log_dev) {
if (log_health[0] != 'A') {
log_debug("%s: Mirror log device marked as failed",
dev_name(dev));
log_debug_activation("%s: Mirror log device marked as failed",
dev_name(dev));
check_for_blocking = 1;
} else {
struct device *tmp_dev;
@ -310,8 +310,8 @@ static int _ignore_blocked_mirror_devices(struct device *dev,
if (strstr(params, "block_on_error") ||
strstr(params, "handle_errors")) {
log_debug("%s: I/O blocked to mirror device",
dev_name(dev));
log_debug_activation("%s: I/O blocked to mirror device",
dev_name(dev));
goto out;
}
}
@ -363,12 +363,12 @@ int device_is_usable(struct device *dev)
uuid = dm_task_get_uuid(dmt);
if (!info.target_count) {
log_debug("%s: Empty device %s not usable.", dev_name(dev), name);
log_debug_activation("%s: Empty device %s not usable.", dev_name(dev), name);
goto out;
}
if (info.suspended && ignore_suspended_devices()) {
log_debug("%s: Suspended device %s not usable.", dev_name(dev), name);
log_debug_activation("%s: Suspended device %s not usable.", dev_name(dev), name);
goto out;
}
@ -379,8 +379,8 @@ int device_is_usable(struct device *dev)
if (target_type && !strcmp(target_type, "mirror") &&
!_ignore_blocked_mirror_devices(dev, start, length, params)) {
log_debug("%s: Mirror device %s not usable.",
dev_name(dev), name);
log_debug_activation("%s: Mirror device %s not usable.",
dev_name(dev), name);
goto out;
}
@ -394,8 +394,8 @@ int device_is_usable(struct device *dev)
*/
if (target_type && !strcmp(target_type, "snapshot-origin") &&
ignore_suspended_devices()) {
log_debug("%s: Snapshot-origin device %s not usable.",
dev_name(dev), name);
log_debug_activation("%s: Snapshot-origin device %s not usable.",
dev_name(dev), name);
goto out;
}
@ -406,8 +406,8 @@ int device_is_usable(struct device *dev)
/* Skip devices consisting entirely of error targets. */
/* FIXME Deal with device stacked above error targets? */
if (only_error_target) {
log_debug("%s: Error device %s not usable.",
dev_name(dev), name);
log_debug_activation("%s: Error device %s not usable.",
dev_name(dev), name);
goto out;
}
@ -420,8 +420,8 @@ int device_is_usable(struct device *dev)
goto_out;
if (lvname && (is_reserved_lvname(lvname) || *layer)) {
log_debug("%s: Reserved internal LV device %s/%s%s%s not usable.",
dev_name(dev), vgname, lvname, *layer ? "-" : "", layer);
log_debug_activation("%s: Reserved internal LV device %s/%s%s%s not usable.",
dev_name(dev), vgname, lvname, *layer ? "-" : "", layer);
goto out;
}
}
@ -473,7 +473,7 @@ int dev_manager_info(struct dm_pool *mem, const struct logical_volume *lv,
return 0;
}
log_debug("Getting device info for %s [%s]", name, dlid);
log_debug_activation("Getting device info for %s [%s]", name, dlid);
r = _info(dlid, with_open_count, with_read_ahead, info, read_ahead);
dm_pool_free(mem, name);
@ -786,7 +786,7 @@ static int _percent_run(struct dev_manager *dm, const char *name,
goto_out;
}
log_debug("LV percent: %f", percent_to_float(*overall_percent));
log_debug_activation("LV percent: %f", percent_to_float(*overall_percent));
r = 1;
out:
@ -980,7 +980,7 @@ int dev_manager_snapshot_percent(struct dev_manager *dm,
/*
* Try and get some info on this device.
*/
log_debug("Getting device status percentage for %s", name);
log_debug_activation("Getting device status percentage for %s", name);
if (!(_percent(dm, name, dlid, "snapshot", 0, NULL, percent,
NULL, fail_if_percent_unsupported)))
return_0;
@ -1011,8 +1011,8 @@ int dev_manager_mirror_percent(struct dev_manager *dm,
return 0;
}
log_debug("Getting device %s status percentage for %s",
target_type, name);
log_debug_activation("Getting device %s status percentage for %s",
target_type, name);
if (!(_percent(dm, name, dlid, target_type, wait, lv, percent,
event_nr, 0)))
return_0;
@ -1033,13 +1033,13 @@ int dev_manager_mirror_percent(struct dev_manager *dm,
else
log_very_verbose("Removing %s", dl->name);
log_debug("Adding target: %" PRIu64 " %" PRIu64 " %s %s",
log_debug_activation("Adding target: %" PRIu64 " %" PRIu64 " %s %s",
extent_size * seg->le, extent_size * seg->len, target, params);
log_debug("Adding target: 0 %" PRIu64 " snapshot-origin %s",
log_debug_activation("Adding target: 0 %" PRIu64 " snapshot-origin %s",
dl->lv->size, params);
log_debug("Adding target: 0 %" PRIu64 " snapshot %s", size, params);
log_debug("Getting device info for %s", dl->name);
log_debug_activation("Adding target: 0 %" PRIu64 " snapshot %s", size, params);
log_debug_activation("Getting device info for %s", dl->name);
/* Rename? */
if ((suffix = strrchr(dl->dlid + sizeof(UUID_PREFIX) - 1, '-')))
@ -1095,7 +1095,7 @@ int dev_manager_thin_pool_status(struct dev_manager *dm,
if (!(dlid = build_dm_uuid(dm->mem, lv->lvid.s, _thin_layer)))
return_0;
log_debug("Getting thin pool device status for %s.", lv->name);
log_debug_activation("Getting thin pool device status for %s.", lv->name);
if (!(dmt = _setup_task(NULL, dlid, 0, DM_DEVICE_STATUS, 0, 0)))
return_0;
@ -1136,7 +1136,7 @@ int dev_manager_thin_pool_percent(struct dev_manager *dm,
if (!(dlid = build_dm_uuid(dm->mem, lv->lvid.s, _thin_layer)))
return_0;
log_debug("Getting device status percentage for %s", name);
log_debug_activation("Getting device status percentage for %s", name);
if (!(_percent(dm, name, dlid, "thin-pool", 0,
(metadata) ? lv : NULL, percent, NULL, 1)))
return_0;
@ -1159,7 +1159,7 @@ int dev_manager_thin_percent(struct dev_manager *dm,
if (!(dlid = build_dm_uuid(dm->mem, lv->lvid.s, layer)))
return_0;
log_debug("Getting device status percentage for %s", name);
log_debug_activation("Getting device status percentage for %s", name);
if (!(_percent(dm, name, dlid, "thin", 0,
(mapped) ? NULL : lv, percent, NULL, 1)))
return_0;
@ -1272,7 +1272,7 @@ static int _add_dev_to_dtree(struct dev_manager *dm, struct dm_tree *dtree,
if (!(dlid = build_dm_uuid(dm->mem, lv->lvid.s, layer)))
return_0;
log_debug("Getting device info for %s [%s]", name, dlid);
log_debug_activation("Getting device info for %s [%s]", name, dlid);
if (!_info(dlid, 1, 0, &info, NULL)) {
log_error("Failed to get info for %s [%s].", name, dlid);
return 0;
@ -1588,7 +1588,7 @@ static struct dm_tree *_create_partial_dtree(struct dev_manager *dm, struct logi
uint32_t s;
if (!(dtree = dm_tree_create())) {
log_debug("Partial dtree creation failed for %s.", lv->name);
log_debug_activation("Partial dtree creation failed for %s.", lv->name);
return NULL;
}
@ -1647,7 +1647,7 @@ static char *_add_error_device(struct dev_manager *dm, struct dm_tree *dtree,
seg->lv->name, errid)))
return_NULL;
log_debug("Getting device info for %s [%s]", name, dlid);
log_debug_activation("Getting device info for %s [%s]", name, dlid);
if (!_info(dlid, 1, 0, &info, NULL)) {
log_error("Failed to get info for %s [%s].", name, dlid);
return 0;
@ -1958,9 +1958,9 @@ static int _add_segment_to_dtree(struct dev_manager *dm,
seg_present->segtype->ops->target_name(seg_present, laopts) :
seg_present->segtype->name);
log_debug("Checking kernel supports %s segment type for %s%s%s",
target_name, seg->lv->name,
layer ? "-" : "", layer ? : "");
log_debug_activation("Checking kernel supports %s segment type for %s%s%s",
target_name, seg->lv->name,
layer ? "-" : "", layer ? : "");
if (seg_present->segtype->ops->target_present &&
!seg_present->segtype->ops->target_present(seg_present->lv->vg->cmd,

View File

@ -486,7 +486,7 @@ int fs_rename_lv(struct logical_volume *lv, const char *dev,
void fs_unlock(void)
{
if (!critical_section()) {
log_debug("Syncing device names");
log_debug_activation("Syncing device names");
/* Wait for all processed udev devices */
if (!dm_udev_wait(_fs_cookie))
stack;

72
lib/cache/lvmcache.c vendored
View File

@ -141,7 +141,7 @@ static void _free_cached_vgmetadata(struct lvmcache_vginfo *vginfo)
vginfo->cft = NULL;
}
log_debug("Metadata cache: VG %s wiped.", vginfo->vgname);
log_debug_cache("Metadata cache: VG %s wiped.", vginfo->vgname);
release_vg(vginfo->cached_vg);
}
@ -184,9 +184,9 @@ static void _store_metadata(struct volume_group *vg, unsigned precommitted)
return;
}
log_debug("Metadata cache: VG %s (%s) stored (%" PRIsize_t " bytes%s).",
vginfo->vgname, uuid, size,
precommitted ? ", precommitted" : "");
log_debug_cache("Metadata cache: VG %s (%s) stored (%" PRIsize_t " bytes%s).",
vginfo->vgname, uuid, size,
precommitted ? ", precommitted" : "");
}
static void _update_cache_info_lock_state(struct lvmcache_info *info,
@ -276,8 +276,8 @@ void lvmcache_commit_metadata(const char *vgname)
return;
if (vginfo->precommitted) {
log_debug("Precommitted metadata cache: VG %s upgraded to committed.",
vginfo->vgname);
log_debug_cache("Precommitted metadata cache: VG %s upgraded to committed.",
vginfo->vgname);
vginfo->precommitted = 0;
}
}
@ -792,9 +792,9 @@ struct volume_group *lvmcache_get_vg(struct cmd_context *cmd, const char *vgname
out:
vginfo->holders++;
vginfo->vg_use_count++;
log_debug("Using cached %smetadata for VG %s with %u holder(s).",
vginfo->precommitted ? "pre-committed " : "",
vginfo->vgname, vginfo->holders);
log_debug_cache("Using cached %smetadata for VG %s with %u holder(s).",
vginfo->precommitted ? "pre-committed " : "",
vginfo->vgname, vginfo->holders);
return vg;
@ -806,15 +806,15 @@ bad:
// #if 0
int lvmcache_vginfo_holders_dec_and_test_for_zero(struct lvmcache_vginfo *vginfo)
{
log_debug("VG %s decrementing %d holder(s) at %p.",
vginfo->cached_vg->name, vginfo->holders, vginfo->cached_vg);
log_debug_cache("VG %s decrementing %d holder(s) at %p.",
vginfo->cached_vg->name, vginfo->holders, vginfo->cached_vg);
if (--vginfo->holders)
return 0;
if (vginfo->vg_use_count > 1)
log_debug("VG %s reused %d times.",
vginfo->cached_vg->name, vginfo->vg_use_count);
log_debug_cache("VG %s reused %d times.",
vginfo->cached_vg->name, vginfo->vg_use_count);
/* Debug perform crc check only when it's been used more then once */
if (!dm_pool_unlock(vginfo->cached_vg->vgmem,
@ -1095,7 +1095,7 @@ static int _lvmcache_update_vgid(struct lvmcache_info *info,
dm_hash_remove(_vgid_hash, vginfo->vgid);
if (!vgid) {
/* FIXME: unreachable code path */
log_debug("lvmcache: %s: clearing VGID", info ? dev_name(info->dev) : vginfo->vgname);
log_debug_cache("lvmcache: %s: clearing VGID", info ? dev_name(info->dev) : vginfo->vgname);
return 1;
}
@ -1108,9 +1108,9 @@ static int _lvmcache_update_vgid(struct lvmcache_info *info,
}
if (!is_orphan_vg(vginfo->vgname))
log_debug("lvmcache: %s: setting %s VGID to %s",
(info) ? dev_name(info->dev) : "",
vginfo->vgname, vginfo->vgid);
log_debug_cache("lvmcache: %s: setting %s VGID to %s",
(info) ? dev_name(info->dev) : "",
vginfo->vgname, vginfo->vgid);
return 1;
}
@ -1287,11 +1287,11 @@ static int _lvmcache_update_vgname(struct lvmcache_info *info,
dm_list_size(&info2->mdas));
else
mdabuf[0] = '\0';
log_debug("lvmcache: %s: now in VG %s%s%s%s%s",
dev_name(info2->dev),
vgname, orphan_vginfo->vgid[0] ? " (" : "",
orphan_vginfo->vgid[0] ? orphan_vginfo->vgid : "",
orphan_vginfo->vgid[0] ? ")" : "", mdabuf);
log_debug_cache("lvmcache: %s: now in VG %s%s%s%s%s",
dev_name(info2->dev),
vgname, orphan_vginfo->vgid[0] ? " (" : "",
orphan_vginfo->vgid[0] ? orphan_vginfo->vgid : "",
orphan_vginfo->vgid[0] ? ")" : "", mdabuf);
}
if (!_drop_vginfo(NULL, primary_vginfo))
@ -1329,13 +1329,13 @@ static int _lvmcache_update_vgname(struct lvmcache_info *info,
sprintf(mdabuf, " with %u mdas", dm_list_size(&info->mdas));
else
mdabuf[0] = '\0';
log_debug("lvmcache: %s: now in VG %s%s%s%s%s",
dev_name(info->dev),
vgname, vginfo->vgid[0] ? " (" : "",
vginfo->vgid[0] ? vginfo->vgid : "",
vginfo->vgid[0] ? ")" : "", mdabuf);
log_debug_cache("lvmcache: %s: now in VG %s%s%s%s%s",
dev_name(info->dev),
vgname, vginfo->vgid[0] ? " (" : "",
vginfo->vgid[0] ? vginfo->vgid : "",
vginfo->vgid[0] ? ")" : "", mdabuf);
} else
log_debug("lvmcache: initialised VG %s", vgname);
log_debug_cache("lvmcache: initialised VG %s", vgname);
return 1;
}
@ -1347,9 +1347,9 @@ static int _lvmcache_update_vgstatus(struct lvmcache_info *info, uint32_t vgstat
return 1;
if ((info->vginfo->status & EXPORTED_VG) != (vgstatus & EXPORTED_VG))
log_debug("lvmcache: %s: VG %s %s exported",
dev_name(info->dev), info->vginfo->vgname,
vgstatus & EXPORTED_VG ? "now" : "no longer");
log_debug_cache("lvmcache: %s: VG %s %s exported",
dev_name(info->dev), info->vginfo->vgname,
vgstatus & EXPORTED_VG ? "now" : "no longer");
info->vginfo->status = vgstatus;
@ -1369,8 +1369,8 @@ static int _lvmcache_update_vgstatus(struct lvmcache_info *info, uint32_t vgstat
return 0;
}
log_debug("lvmcache: %s: VG %s: Set creation host to %s.",
dev_name(info->dev), info->vginfo->vgname, creation_host);
log_debug_cache("lvmcache: %s: VG %s: Set creation host to %s.",
dev_name(info->dev), info->vginfo->vgname, creation_host);
return 1;
}
@ -1519,9 +1519,9 @@ struct lvmcache_info *lvmcache_add(struct labeller *labeller, const char *pvid,
dev_name(existing->dev));
}
if (strcmp(pvid_s, existing->dev->pvid))
log_debug("Updating pvid cache to %s (%s) from %s (%s)",
pvid_s, dev_name(dev),
existing->dev->pvid, dev_name(existing->dev));
log_debug_cache("Updating pvid cache to %s (%s) from %s (%s)",
pvid_s, dev_name(dev),
existing->dev->pvid, dev_name(existing->dev));
/* Switch over to new preferred device */
existing->dev = dev;
info = existing;

32
lib/cache/lvmetad.c vendored
View File

@ -53,8 +53,8 @@ static void _lvmetad_connect()
_lvmetad = lvmetad_open(_lvmetad_socket);
if (_lvmetad.socket_fd >= 0 && !_lvmetad.error) {
log_debug("Successfully connected to lvmetad on fd %d.",
_lvmetad.socket_fd);
log_debug_lvmetad("Successfully connected to lvmetad on fd %d.",
_lvmetad.socket_fd);
_lvmetad_connected = 1;
}
}
@ -81,7 +81,7 @@ int lvmetad_active(void)
_lvmetad_connect();
if ((_lvmetad.socket_fd < 0 || _lvmetad.error))
log_debug("Failed to connect to lvmetad: %s.", strerror(_lvmetad.error));
log_debug_lvmetad("Failed to connect to lvmetad: %s.", strerror(_lvmetad.error));
return _lvmetad_connected;
}
@ -156,7 +156,7 @@ retry:
static int _token_update(void)
{
log_debug("Sending updated token to lvmetad: %s", _lvmetad_token ? : "<NONE>");
log_debug_lvmetad("Sending updated token to lvmetad: %s", _lvmetad_token ? : "<NONE>");
daemon_reply repl = _lvmetad_send("token_update", NULL);
if (repl.error || strcmp(daemon_reply_str(repl, "response", ""), "OK")) {
@ -323,12 +323,12 @@ struct volume_group *lvmetad_vg_lookup(struct cmd_context *cmd, const char *vgna
if (vgid) {
if (!id_write_format((const struct id*)vgid, uuid, sizeof(uuid)))
return_NULL;
log_debug("Asking lvmetad for VG %s (%s)", uuid, vgname ? : "name unknown");
log_debug_lvmetad("Asking lvmetad for VG %s (%s)", uuid, vgname ? : "name unknown");
reply = _lvmetad_send("vg_lookup", "uuid = %s", uuid, NULL);
} else {
if (!vgname)
log_error(INTERNAL_ERROR "VG name required (VGID not available)");
log_debug("Asking lvmetad for VG %s", vgname);
log_debug_lvmetad("Asking lvmetad for VG %s", vgname);
reply = _lvmetad_send("vg_lookup", "name = %s", vgname, NULL);
}
@ -439,7 +439,7 @@ int lvmetad_vg_update(struct volume_group *vg)
if (!(vgmeta = _export_vg_to_config_tree(vg)))
return_0;
log_debug("Sending lvmetad updated metadata for VG %s (seqno %" PRIu32 ")", vg->name, vg->seqno);
log_debug_lvmetad("Sending lvmetad updated metadata for VG %s (seqno %" PRIu32 ")", vg->name, vg->seqno);
reply = _lvmetad_send("vg_update", "vgname = %s", vg->name,
"metadata = %t", vgmeta, NULL);
dm_config_destroy(vgmeta);
@ -492,7 +492,7 @@ int lvmetad_vg_remove(struct volume_group *vg)
if (!id_write_format(&vg->id, uuid, sizeof(uuid)))
return_0;
log_debug("Telling lvmetad to remove VGID %s (%s)", uuid, vg->name);
log_debug_lvmetad("Telling lvmetad to remove VGID %s (%s)", uuid, vg->name);
reply = _lvmetad_send("vg_remove", "uuid = %s", uuid, NULL);
result = _lvmetad_handle_reply(reply, "remove VG", vg->name, NULL);
@ -514,7 +514,7 @@ int lvmetad_pv_lookup(struct cmd_context *cmd, struct id pvid, int *found)
if (!id_write_format(&pvid, uuid, sizeof(uuid)))
return_0;
log_debug("Asking lvmetad for PV %s", uuid);
log_debug_lvmetad("Asking lvmetad for PV %s", uuid);
reply = _lvmetad_send("pv_lookup", "uuid = %s", uuid, NULL);
if (!_lvmetad_handle_reply(reply, "lookup PV", "", found))
goto_out;
@ -545,7 +545,7 @@ int lvmetad_pv_lookup_by_dev(struct cmd_context *cmd, struct device *dev, int *f
if (!lvmetad_active())
return_0;
log_debug("Asking lvmetad for PV on %s", dev_name(dev));
log_debug_lvmetad("Asking lvmetad for PV on %s", dev_name(dev));
reply = _lvmetad_send("pv_lookup", "device = %" PRId64, (int64_t) dev->dev, NULL);
if (!_lvmetad_handle_reply(reply, "lookup PV", dev_name(dev), found))
goto_out;
@ -573,7 +573,7 @@ int lvmetad_pv_list_to_lvmcache(struct cmd_context *cmd)
if (!lvmetad_active())
return 1;
log_debug("Asking lvmetad for complete list of known PVs");
log_debug_lvmetad("Asking lvmetad for complete list of known PVs");
reply = _lvmetad_send("pv_list", NULL);
if (!_lvmetad_handle_reply(reply, "list PVs", "", NULL)) {
daemon_reply_destroy(reply);
@ -600,7 +600,7 @@ int lvmetad_vg_list_to_lvmcache(struct cmd_context *cmd)
if (!lvmetad_active())
return 1;
log_debug("Asking lvmetad for complete list of known VGs");
log_debug_lvmetad("Asking lvmetad for complete list of known VGs");
reply = _lvmetad_send("vg_list", NULL);
if (!_lvmetad_handle_reply(reply, "list VGs", "", NULL)) {
daemon_reply_destroy(reply);
@ -738,7 +738,7 @@ int lvmetad_pv_found(const struct id *pvid, struct device *dev, const struct for
return_0;
}
log_debug("Telling lvmetad to store PV %s (%s) in VG %s", dev_name(dev), uuid, vg->name);
log_debug_lvmetad("Telling lvmetad to store PV %s (%s) in VG %s", dev_name(dev), uuid, vg->name);
reply = _lvmetad_send("pv_found",
"pvmeta = %t", pvmeta,
"vgname = %s", vg->name,
@ -750,7 +750,7 @@ int lvmetad_pv_found(const struct id *pvid, struct device *dev, const struct for
* There is no VG metadata stored on this PV.
* It might or might not be an orphan.
*/
log_debug("Telling lvmetad to store PV %s (%s)", dev_name(dev), uuid);
log_debug_lvmetad("Telling lvmetad to store PV %s (%s)", dev_name(dev), uuid);
reply = _lvmetad_send("pv_found", "pvmeta = %t", pvmeta, NULL);
}
@ -798,7 +798,7 @@ int lvmetad_pv_gone(dev_t devno, const char *pv_name, activation_handler handler
* the whole stack from top to bottom (not yet upstream).
*/
log_debug("Telling lvmetad to forget any PV on %s", pv_name);
log_debug_lvmetad("Telling lvmetad to forget any PV on %s", pv_name);
reply = _lvmetad_send("pv_gone", "device = %" PRId64, (int64_t) devno, NULL);
result = _lvmetad_handle_reply(reply, "drop PV", pv_name, &found);
@ -925,7 +925,7 @@ int lvmetad_pvscan_all_devs(struct cmd_context *cmd, activation_handler handler)
return 0;
}
log_debug("Telling lvmetad to clear its cache");
log_debug_lvmetad("Telling lvmetad to clear its cache");
reply = _lvmetad_send("pv_clear_all", NULL);
if (!_lvmetad_handle_reply(reply, "clear info about all PVs", "", NULL))
r = 0;

View File

@ -137,7 +137,7 @@ void dev_set_preferred_name(struct str_list *sl, struct device *dev)
if (_cache.preferred_names_matcher)
return;
log_debug("%s: New preferred name", sl->str);
log_debug_devs("%s: New preferred name", sl->str);
dm_list_del(&sl->list);
dm_list_add_h(&dev->aliases, &sl->list);
}
@ -315,7 +315,7 @@ static int _add_alias(struct device *dev, const char *path)
/* Is name already there? */
dm_list_iterate_items(strl, &dev->aliases) {
if (!strcmp(strl->str, path)) {
log_debug("%s: Already in device cache", path);
log_debug_devs("%s: Already in device cache", path);
return 1;
}
}
@ -325,11 +325,11 @@ static int _add_alias(struct device *dev, const char *path)
if (!dm_list_empty(&dev->aliases)) {
oldpath = dm_list_item(dev->aliases.n, struct str_list)->str;
prefer_old = _compare_paths(path, oldpath);
log_debug("%s: Aliased to %s in device cache%s",
path, oldpath, prefer_old ? "" : " (preferred name)");
log_debug_devs("%s: Aliased to %s in device cache%s",
path, oldpath, prefer_old ? "" : " (preferred name)");
} else
log_debug("%s: Added to device cache", path);
log_debug_devs("%s: Added to device cache", path);
if (prefer_old)
dm_list_add(&dev->aliases, &sl->list);
@ -464,7 +464,7 @@ static int _insert_file(const char *path)
}
if (!S_ISREG(info.st_mode)) {
log_debug("%s: Not a regular file", path);
log_debug_devs("%s: Not a regular file", path);
return 0;
}
@ -563,13 +563,13 @@ static void _insert_dirs(struct dm_list *dirs)
dm_list_iterate_items(dl, &_cache.dirs) {
if (with_udev) {
if (!_insert_udev_dir(udev, dl->dir))
log_debug("%s: Failed to insert devices from "
"udev-managed directory to device "
"cache fully", dl->dir);
log_debug_devs("%s: Failed to insert devices from "
"udev-managed directory to device "
"cache fully", dl->dir);
}
else if (!_insert_dir(dl->dir))
log_debug("%s: Failed to insert devices to "
"device cache fully", dl->dir);
log_debug_devs("%s: Failed to insert devices to "
"device cache fully", dl->dir);
}
}
@ -613,7 +613,7 @@ static int _insert(const char *path, int rec, int check_with_udev_db)
}
if (S_ISLNK(info.st_mode)) {
log_debug("%s: Symbolic link to directory", path);
log_debug_devs("%s: Symbolic link to directory", path);
return 0;
}
@ -622,7 +622,7 @@ static int _insert(const char *path, int rec, int check_with_udev_db)
} else { /* add a device */
if (!S_ISBLK(info.st_mode)) {
log_debug("%s: Not a block device", path);
log_debug_devs("%s: Not a block device", path);
return 0;
}
@ -869,9 +869,9 @@ const char *dev_name_confirmed(struct device *dev, int quiet)
log_sys_error("stat", name);
}
if (quiet)
log_debug("Path %s no longer valid for device(%d,%d)",
name, (int) MAJOR(dev->dev),
(int) MINOR(dev->dev));
log_debug_devs("Path %s no longer valid for device(%d,%d)",
name, (int) MAJOR(dev->dev),
(int) MINOR(dev->dev));
else
log_warn("Path %s no longer valid for device(%d,%d)",
name, (int) MAJOR(dev->dev),
@ -891,8 +891,8 @@ const char *dev_name_confirmed(struct device *dev, int quiet)
}
/* Scanning issues this inappropriately sometimes. */
log_debug("Aborting - please provide new pathname for what "
"used to be %s", name);
log_debug_devs("Aborting - please provide new pathname for what "
"used to be %s", name);
return NULL;
}

View File

@ -134,7 +134,7 @@ static int _get_block_size(struct device *dev, unsigned int *size)
log_sys_error("ioctl BLKBSZGET", name);
return 0;
}
log_debug("%s: block size is %u bytes", name, dev->block_size);
log_debug_devs("%s: block size is %u bytes", name, dev->block_size);
}
*size = (unsigned int) dev->block_size;
@ -314,8 +314,8 @@ static int _dev_discard_blocks(struct device *dev, uint64_t offset_bytes, uint64
discard_range[0] = offset_bytes;
discard_range[1] = size_bytes;
log_debug("Discarding %" PRIu64 " bytes offset %" PRIu64 " bytes on %s.",
size_bytes, offset_bytes, dev_name(dev));
log_debug_devs("Discarding %" PRIu64 " bytes offset %" PRIu64 " bytes on %s.",
size_bytes, offset_bytes, dev_name(dev));
if (ioctl(dev->fd, BLKDISCARD, &discard_range) < 0) {
log_error("%s: BLKDISCARD ioctl at offset %" PRIu64 " size %" PRIu64 " failed: %s.",
dev_name(dev), offset_bytes, size_bytes, strerror(errno));
@ -431,8 +431,8 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
}
if (dev->open_count && !need_excl) {
log_debug("%s already opened read-only. Upgrading "
"to read-write.", dev_name(dev));
log_debug_devs("%s already opened read-only. Upgrading "
"to read-write.", dev_name(dev));
dev->open_count++;
}
@ -442,7 +442,7 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
if (critical_section())
/* FIXME Make this log_error */
log_verbose("dev_open(%s) called while suspended",
dev_name(dev));
dev_name(dev));
if (dev->flags & DEV_REGULAR)
name = dev_name(dev);
@ -471,7 +471,7 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
flags &= ~O_DIRECT;
if ((dev->fd = open(name, flags, 0777)) >= 0) {
dev->flags &= ~DEV_O_DIRECT;
log_debug("%s: Not using O_DIRECT", name);
log_debug_devs("%s: Not using O_DIRECT", name);
goto opened;
}
}
@ -518,10 +518,10 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
dm_list_add(&_open_devices, &dev->open_list);
log_debug("Opened %s %s%s%s", dev_name(dev),
dev->flags & DEV_OPENED_RW ? "RW" : "RO",
dev->flags & DEV_OPENED_EXCL ? " O_EXCL" : "",
dev->flags & DEV_O_DIRECT ? " O_DIRECT" : "");
log_debug_devs("Opened %s %s%s%s", dev_name(dev),
dev->flags & DEV_OPENED_RW ? "RW" : "RO",
dev->flags & DEV_OPENED_EXCL ? " O_EXCL" : "",
dev->flags & DEV_O_DIRECT ? " O_DIRECT" : "");
return 1;
}
@ -574,7 +574,7 @@ static void _close(struct device *dev)
dev->block_size = -1;
dm_list_del(&dev->open_list);
log_debug("Closed %s", dev_name(dev));
log_debug_devs("Closed %s", dev_name(dev));
if (dev->flags & DEV_ALLOCED) {
dm_free((void *) dm_list_item(dev->aliases.n, struct str_list)->
@ -602,8 +602,8 @@ static int _dev_close(struct device *dev, int immediate)
dev->open_count--;
if (immediate && dev->open_count)
log_debug("%s: Immediate close attempt while still referenced",
dev_name(dev));
log_debug_devs("%s: Immediate close attempt while still referenced",
dev_name(dev));
/* Close unless device is known to belong to a locked VG */
if (immediate ||
@ -756,12 +756,12 @@ int dev_set(struct device *dev, uint64_t offset, size_t len, int value)
return_0;
if ((offset % SECTOR_SIZE) || (len % SECTOR_SIZE))
log_debug("Wiping %s at %" PRIu64 " length %" PRIsize_t,
dev_name(dev), offset, len);
log_debug_devs("Wiping %s at %" PRIu64 " length %" PRIsize_t,
dev_name(dev), offset, len);
else
log_debug("Wiping %s at sector %" PRIu64 " length %" PRIsize_t
" sectors", dev_name(dev), offset >> SECTOR_SHIFT,
len >> SECTOR_SHIFT);
log_debug_devs("Wiping %s at sector %" PRIu64 " length %" PRIsize_t
" sectors", dev_name(dev), offset >> SECTOR_SHIFT,
len >> SECTOR_SHIFT);
memset(buffer, value, sizeof(buffer));
while (1) {

View File

@ -28,7 +28,7 @@ static int _and_p(struct dev_filter *f, struct device *dev)
filters++;
}
log_debug("Using %s", dev_name(dev));
log_debug_devs("Using %s", dev_name(dev));
return 1;
}

View File

@ -29,13 +29,13 @@ static int _ignore_md(struct dev_filter *f __attribute__((unused)),
ret = dev_is_md(dev, NULL);
if (ret == 1) {
log_debug("%s: Skipping md component device", dev_name(dev));
log_debug_devs("%s: Skipping md component device", dev_name(dev));
return 0;
}
if (ret < 0) {
log_debug("%s: Skipping: error in md component detection",
dev_name(dev));
log_debug_devs("%s: Skipping: error in md component detection",
dev_name(dev));
return 0;
}

View File

@ -160,7 +160,7 @@ static int dev_is_mpath(struct dev_filter *f, struct device *dev)
static int _ignore_mpath(struct dev_filter *f, struct device *dev)
{
if (dev_is_mpath(f, dev) == 1) {
log_debug("%s: Skipping mpath component device", dev_name(dev));
log_debug_devs("%s: Skipping mpath component device", dev_name(dev));
return 0;
}

View File

@ -282,7 +282,7 @@ static int _lookup_p(struct dev_filter *f, struct device *dev)
/* Cached BAD? */
if (l == PF_BAD_DEVICE) {
log_debug("%s: Skipping (cached)", dev_name(dev));
log_debug_devs("%s: Skipping (cached)", dev_name(dev));
return 0;
}
@ -295,7 +295,7 @@ static int _lookup_p(struct dev_filter *f, struct device *dev)
return 0;
}
if (!device_is_usable(dev)) {
log_debug("%s: Skipping unusable device", dev_name(dev));
log_debug_devs("%s: Skipping unusable device", dev_name(dev));
return 0;
}
return pf->real->passes_filter(pf->real, dev);

View File

@ -170,7 +170,7 @@ static int _accept_p(struct dev_filter *f, struct device *dev)
}
if (rejected)
log_debug("%s: Skipping (regex)", dev_name(dev));
log_debug_devs("%s: Skipping (regex)", dev_name(dev));
/*
* pass everything that doesn't match

View File

@ -274,7 +274,7 @@ static int _accept_p(struct dev_filter *f, struct device *dev)
return 1;
if (!_set_lookup(ds, dev->dev)) {
log_debug("%s: Skipping (sysfs)", dev_name(dev));
log_debug_devs("%s: Skipping (sysfs)", dev_name(dev));
return 0;
} else
return 1;

View File

@ -105,31 +105,31 @@ static int _passes_lvm_type_device_filter(struct dev_filter *f __attribute__((un
/* Is this a recognised device type? */
if (!_partitions[MAJOR(dev->dev)].max_partitions) {
log_debug("%s: Skipping: Unrecognised LVM device type %"
PRIu64, name, (uint64_t) MAJOR(dev->dev));
log_debug_devs("%s: Skipping: Unrecognised LVM device type %"
PRIu64, name, (uint64_t) MAJOR(dev->dev));
return 0;
}
/* Check it's accessible */
if (!dev_open_readonly_quiet(dev)) {
log_debug("%s: Skipping: open failed", name);
log_debug_devs("%s: Skipping: open failed", name);
return 0;
}
/* Check it's not too small */
if (!dev_get_size(dev, &size)) {
log_debug("%s: Skipping: dev_get_size failed", name);
log_debug_devs("%s: Skipping: dev_get_size failed", name);
goto out;
}
if (size < pv_min_size()) {
log_debug("%s: Skipping: Too small to hold a PV", name);
log_debug_devs("%s: Skipping: Too small to hold a PV", name);
goto out;
}
if (is_partitioned_dev(dev)) {
log_debug("%s: Skipping: Partition table signature found",
name);
log_debug_devs("%s: Skipping: Partition table signature found",
name);
goto out;
}

View File

@ -535,8 +535,8 @@ static int _write_vgd(struct disk_list *data)
struct vg_disk *vgd = &data->vgd;
uint64_t pos = data->pvd.vg_on_disk.base;
log_debug("Writing %s VG metadata to %s at %" PRIu64 " len %" PRIsize_t,
data->pvd.vg_name, dev_name(data->dev), pos, sizeof(*vgd));
log_debug_metadata("Writing %s VG metadata to %s at %" PRIu64 " len %" PRIsize_t,
data->pvd.vg_name, dev_name(data->dev), pos, sizeof(*vgd));
_xlate_vgd(vgd);
if (!dev_write(data->dev, pos, sizeof(*vgd), vgd))
@ -560,9 +560,9 @@ static int _write_uuids(struct disk_list *data)
return 0;
}
log_debug("Writing %s uuidlist to %s at %" PRIu64 " len %d",
data->pvd.vg_name, dev_name(data->dev),
pos, NAME_LEN);
log_debug_metadata("Writing %s uuidlist to %s at %" PRIu64 " len %d",
data->pvd.vg_name, dev_name(data->dev),
pos, NAME_LEN);
if (!dev_write(data->dev, pos, NAME_LEN, ul->uuid))
return_0;
@ -575,9 +575,9 @@ static int _write_uuids(struct disk_list *data)
static int _write_lvd(struct device *dev, uint64_t pos, struct lv_disk *disk)
{
log_debug("Writing %s LV %s metadata to %s at %" PRIu64 " len %"
PRIsize_t, disk->vg_name, disk->lv_name, dev_name(dev),
pos, sizeof(*disk));
log_debug_metadata("Writing %s LV %s metadata to %s at %" PRIu64 " len %"
PRIsize_t, disk->vg_name, disk->lv_name, dev_name(dev),
pos, sizeof(*disk));
_xlate_lvd(disk);
if (!dev_write(dev, pos, sizeof(*disk), disk))
@ -621,9 +621,9 @@ static int _write_extents(struct disk_list *data)
struct pe_disk *extents = data->extents;
uint64_t pos = data->pvd.pe_on_disk.base;
log_debug("Writing %s extents metadata to %s at %" PRIu64 " len %"
PRIsize_t, data->pvd.vg_name, dev_name(data->dev),
pos, len);
log_debug_metadata("Writing %s extents metadata to %s at %" PRIu64 " len %"
PRIsize_t, data->pvd.vg_name, dev_name(data->dev),
pos, len);
_xlate_extents(extents, data->pvd.pe_total);
if (!dev_write(data->dev, pos, len, extents))
@ -656,9 +656,9 @@ static int _write_pvd(struct disk_list *data)
memcpy(buf, &data->pvd, sizeof(struct pv_disk));
log_debug("Writing %s PV metadata to %s at %" PRIu64 " len %"
PRIsize_t, data->pvd.vg_name, dev_name(data->dev),
pos, size);
log_debug_metadata("Writing %s PV metadata to %s at %" PRIu64 " len %"
PRIsize_t, data->pvd.vg_name, dev_name(data->dev),
pos, size);
_xlate_pvd((struct pv_disk *) buf);
if (!dev_write(data->dev, pos, size, buf)) {

View File

@ -67,35 +67,35 @@ static int _check_vgs(struct dm_list *pvs, struct volume_group *vg)
else if (memcmp(&first->vgd, &dl->vgd, sizeof(first->vgd))) {
log_error("VG data differs between PVs %s and %s",
dev_name(first->dev), dev_name(dl->dev));
log_debug("VG data on %s: %s %s %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32,
dev_name(first->dev), first->vgd.vg_uuid,
first->vgd.vg_name_dummy,
first->vgd.vg_number, first->vgd.vg_access,
first->vgd.vg_status, first->vgd.lv_max,
first->vgd.lv_cur, first->vgd.lv_open,
first->vgd.pv_max, first->vgd.pv_cur,
first->vgd.pv_act, first->vgd.dummy,
first->vgd.vgda, first->vgd.pe_size,
first->vgd.pe_total, first->vgd.pe_allocated,
first->vgd.pvg_total);
log_debug("VG data on %s: %s %s %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32,
dev_name(dl->dev), dl->vgd.vg_uuid,
dl->vgd.vg_name_dummy, dl->vgd.vg_number,
dl->vgd.vg_access, dl->vgd.vg_status,
dl->vgd.lv_max, dl->vgd.lv_cur,
dl->vgd.lv_open, dl->vgd.pv_max,
dl->vgd.pv_cur, dl->vgd.pv_act, dl->vgd.dummy,
dl->vgd.vgda, dl->vgd.pe_size,
dl->vgd.pe_total, dl->vgd.pe_allocated,
dl->vgd.pvg_total);
log_debug_metadata("VG data on %s: %s %s %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32,
dev_name(first->dev), first->vgd.vg_uuid,
first->vgd.vg_name_dummy,
first->vgd.vg_number, first->vgd.vg_access,
first->vgd.vg_status, first->vgd.lv_max,
first->vgd.lv_cur, first->vgd.lv_open,
first->vgd.pv_max, first->vgd.pv_cur,
first->vgd.pv_act, first->vgd.dummy,
first->vgd.vgda, first->vgd.pe_size,
first->vgd.pe_total, first->vgd.pe_allocated,
first->vgd.pvg_total);
log_debug_metadata("VG data on %s: %s %s %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32 " %" PRIu32
" %" PRIu32 " %" PRIu32 " %" PRIu32 " %"
PRIu32 " %" PRIu32 " %" PRIu32,
dev_name(dl->dev), dl->vgd.vg_uuid,
dl->vgd.vg_name_dummy, dl->vgd.vg_number,
dl->vgd.vg_access, dl->vgd.vg_status,
dl->vgd.lv_max, dl->vgd.lv_cur,
dl->vgd.lv_open, dl->vgd.pv_max,
dl->vgd.pv_cur, dl->vgd.pv_act, dl->vgd.dummy,
dl->vgd.vgda, dl->vgd.pe_size,
dl->vgd.pe_total, dl->vgd.pe_allocated,
dl->vgd.pvg_total);
dm_list_del(pvh);
return 0;
}
@ -168,8 +168,8 @@ static int _fix_partial_vg(struct volume_group *vg, struct dm_list *pvs)
goto_out;
add_pvl_to_vgs(vg, pvl);
log_debug("%s: partial VG, allocated missing PV using %d extents.",
vg->name, pvl->pv->pe_count);
log_debug_metadata("%s: partial VG, allocated missing PV using %d extents.",
vg->name, pvl->pv->pe_count);
return 1;
out:

View File

@ -91,11 +91,11 @@ int read_pool_label(struct pool_list *pl, struct labeller *l,
get_pool_pv_uuid(&pvid, pd);
id_write_format(&pvid, uuid, ID_LEN + 7);
log_debug("Calculated uuid %s for %s", uuid, dev_name(dev));
log_debug_metadata("Calculated uuid %s for %s", uuid, dev_name(dev));
get_pool_vg_uuid(&vgid, pd);
id_write_format(&vgid, uuid, ID_LEN + 7);
log_debug("Calculated uuid %s for %s", uuid, pd->pl_pool_name);
log_debug_metadata("Calculated uuid %s for %s", uuid, pd->pl_pool_name);
if (!(info = lvmcache_add(l, (char *) &pvid, dev, pd->pl_pool_name,
(char *) &vgid, 0)))
@ -369,8 +369,8 @@ int read_pool_pds(const struct format_type *fmt, const char *vg_name,
full_scan++;
if (full_scan > 1) {
log_debug("No devices for vg %s found in cache",
vg_name);
log_debug_metadata("No devices for vg %s found in cache",
vg_name);
return 0;
}
lvmcache_label_scan(fmt->cmd, full_scan);

View File

@ -77,8 +77,8 @@ int import_pool_lvs(struct volume_group *vg, struct dm_pool *mem, struct dm_list
return_0;
get_pool_lv_uuid(lv->lvid.id, &pl->pd);
log_debug("Calculated lv uuid for lv %s: %s", lv->name,
lv->lvid.s);
log_debug_metadata("Calculated lv uuid for lv %s: %s", lv->name,
lv->lvid.s);
lv->status |= VISIBLE_LV | LVM_READ | LVM_WRITE;
lv->major = POOL_MAJOR;
@ -167,8 +167,8 @@ static const char *_cvt_sptype(uint32_t sptype)
break;
}
}
log_debug("Found sptype %X and converted it to %s",
sptype, sptype_names[i].name);
log_debug_metadata("Found sptype %X and converted it to %s",
sptype, sptype_names[i].name);
return sptype_names[i].name;
}

View File

@ -119,8 +119,8 @@ static int _extend_buffer(struct formatter *f)
{
char *newbuf;
log_debug("Doubling metadata output buffer to %" PRIu32,
f->data.buf.size * 2);
log_debug_metadata("Doubling metadata output buffer to %" PRIu32,
f->data.buf.size * 2);
if (!(newbuf = dm_realloc(f->data.buf.start,
f->data.buf.size * 2))) {
log_error("Buffer reallocation failed.");

View File

@ -427,8 +427,8 @@ static struct raw_locn *_find_vg_rlocn(struct device_area *dev_area,
(isspace(vgnamebuf[len]) || vgnamebuf[len] == '{'))
return rlocn;
else
log_debug("Volume group name found in metadata does "
"not match expected name %s.", vgname);
log_debug_metadata("Volume group name found in metadata does "
"not match expected name %s.", vgname);
bad:
if ((info = lvmcache_info_from_pvid(dev_area->dev->pvid, 0)))
@ -495,7 +495,7 @@ static struct volume_group *_vg_read_raw_area(struct format_instance *fid,
goto_out;
if (!(rlocn = _find_vg_rlocn(area, mdah, vgname, &precommitted))) {
log_debug("VG %s not found on %s", vgname, dev_name(area->dev));
log_debug_metadata("VG %s not found on %s", vgname, dev_name(area->dev));
goto out;
}
@ -516,10 +516,10 @@ static struct volume_group *_vg_read_raw_area(struct format_instance *fid,
wrap, calc_crc, rlocn->checksum, &when,
&desc)))
goto_out;
log_debug("Read %s %smetadata (%u) from %s at %" PRIu64 " size %"
PRIu64, vg->name, precommitted ? "pre-commit " : "",
vg->seqno, dev_name(area->dev),
area->start + rlocn->offset, rlocn->size);
log_debug_metadata("Read %s %smetadata (%u) from %s at %" PRIu64 " size %"
PRIu64, vg->name, precommitted ? "pre-commit " : "",
vg->seqno, dev_name(area->dev),
area->start + rlocn->offset, rlocn->size);
if (precommitted)
vg->status |= PRECOMMITTED;
@ -625,9 +625,9 @@ static int _vg_write_raw(struct format_instance *fid, struct volume_group *vg,
goto out;
}
log_debug("Writing %s metadata to %s at %" PRIu64 " len %" PRIu64,
vg->name, dev_name(mdac->area.dev), mdac->area.start +
mdac->rlocn.offset, mdac->rlocn.size - new_wrap);
log_debug_metadata("Writing %s metadata to %s at %" PRIu64 " len %" PRIu64,
vg->name, dev_name(mdac->area.dev), mdac->area.start +
mdac->rlocn.offset, mdac->rlocn.size - new_wrap);
/* Write text out, circularly */
if (!dev_write(mdac->area.dev, mdac->area.start + mdac->rlocn.offset,
@ -636,9 +636,9 @@ static int _vg_write_raw(struct format_instance *fid, struct volume_group *vg,
goto_out;
if (new_wrap) {
log_debug("Writing metadata to %s at %" PRIu64 " len %" PRIu64,
dev_name(mdac->area.dev), mdac->area.start +
MDA_HEADER_SIZE, new_wrap);
log_debug_metadata("Writing metadata to %s at %" PRIu64 " len %" PRIu64,
dev_name(mdac->area.dev), mdac->area.start +
MDA_HEADER_SIZE, new_wrap);
if (!dev_write(mdac->area.dev,
mdac->area.start + MDA_HEADER_SIZE,
@ -730,13 +730,13 @@ static int _vg_commit_raw_rlocn(struct format_instance *fid,
rlocn->offset = mdac->rlocn.offset;
rlocn->size = mdac->rlocn.size;
rlocn->checksum = mdac->rlocn.checksum;
log_debug("%sCommitting %s metadata (%u) to %s header at %"
log_debug_metadata("%sCommitting %s metadata (%u) to %s header at %"
PRIu64, precommit ? "Pre-" : "", vg->name, vg->seqno,
dev_name(mdac->area.dev), mdac->area.start);
} else
log_debug("Wiping pre-committed %s metadata from %s "
"header at %" PRIu64, vg->name,
dev_name(mdac->area.dev), mdac->area.start);
log_debug_metadata("Wiping pre-committed %s metadata from %s "
"header at %" PRIu64, vg->name,
dev_name(mdac->area.dev), mdac->area.start);
rlocn_set_ignored(mdah->raw_locns, mda_is_ignored(mda));
@ -862,7 +862,7 @@ static struct volume_group *_vg_read_file_name(struct format_instance *fid,
read_path, vgname);
return NULL;
} else
log_debug("Read volume group %s from %s", vg->name, read_path);
log_debug_metadata("Read volume group %s from %s", vg->name, read_path);
return vg;
}
@ -929,7 +929,7 @@ static int _vg_write_file(struct format_instance *fid __attribute__((unused)),
return 0;
}
log_debug("Writing %s metadata to %s", vg->name, temp_file);
log_debug_metadata("Writing %s metadata to %s", vg->name, temp_file);
if (!text_vg_export_file(vg, tc->desc, fp)) {
log_error("Failed to write metadata to %s.", temp_file);
@ -949,7 +949,7 @@ static int _vg_write_file(struct format_instance *fid __attribute__((unused)),
return_0;
if (rename(temp_file, tc->path_edit)) {
log_debug("Renaming %s to %s", temp_file, tc->path_edit);
log_debug_metadata("Renaming %s to %s", temp_file, tc->path_edit);
log_error("%s: rename to %s failed: %s", temp_file,
tc->path_edit, strerror(errno));
return 0;
@ -968,13 +968,13 @@ static int _vg_commit_file_backup(struct format_instance *fid __attribute__((unu
log_verbose("Test mode: Skipping committing %s metadata (%u)",
vg->name, vg->seqno);
if (unlink(tc->path_edit)) {
log_debug("Unlinking %s", tc->path_edit);
log_debug_metadata("Unlinking %s", tc->path_edit);
log_sys_error("unlink", tc->path_edit);
return 0;
}
} else {
log_debug("Committing %s metadata (%u)", vg->name, vg->seqno);
log_debug("Renaming %s to %s", tc->path_edit, tc->path_live);
log_debug_metadata("Committing %s metadata (%u)", vg->name, vg->seqno);
log_debug_metadata("Renaming %s to %s", tc->path_edit, tc->path_live);
if (rename(tc->path_edit, tc->path_live)) {
log_error("%s: rename to %s failed: %s", tc->path_edit,
tc->path_live, strerror(errno));
@ -1008,7 +1008,7 @@ static int _vg_commit_file(struct format_instance *fid, struct volume_group *vg,
len = slash - tc->path_live;
strncpy(new_name, tc->path_live, len);
strcpy(new_name + len, vg->name);
log_debug("Renaming %s to %s", tc->path_live, new_name);
log_debug_metadata("Renaming %s to %s", tc->path_live, new_name);
if (test_mode())
log_verbose("Test mode: Skipping rename");
else {
@ -1186,11 +1186,11 @@ const char *vgname_from_mda(const struct format_type *fmt,
goto_out;
}
log_debug("%s: Found metadata at %" PRIu64 " size %" PRIu64
" (in area at %" PRIu64 " size %" PRIu64
") for %s (%s)",
dev_name(dev_area->dev), dev_area->start + rlocn->offset,
rlocn->size, dev_area->start, dev_area->size, vgname, uuid);
log_debug_metadata("%s: Found metadata at %" PRIu64 " size %" PRIu64
" (in area at %" PRIu64 " size %" PRIu64
") for %s (%s)",
dev_name(dev_area->dev), dev_area->start + rlocn->offset,
rlocn->size, dev_area->start, dev_area->size, vgname, uuid);
if (mda_free_sectors) {
current_usage = (rlocn->size + SECTOR_SIZE - UINT64_C(1)) -
@ -1320,11 +1320,11 @@ static int _text_pv_write(const struct format_type *fmt, struct physical_volume
continue;
mdac = (struct mda_context *) mda->metadata_locn;
log_debug("Creating metadata area on %s at sector %"
PRIu64 " size %" PRIu64 " sectors",
dev_name(mdac->area.dev),
mdac->area.start >> SECTOR_SHIFT,
mdac->area.size >> SECTOR_SHIFT);
log_debug_metadata("Creating metadata area on %s at sector %"
PRIu64 " size %" PRIu64 " sectors",
dev_name(mdac->area.dev),
mdac->area.start >> SECTOR_SHIFT,
mdac->area.size >> SECTOR_SHIFT);
// if fmt is not the same as info->fmt we are in trouble
lvmcache_add_mda(info, mdac->area.dev,

View File

@ -123,32 +123,32 @@ static int _text_write(struct label *label, void *buf)
!xlate64(pvhdr->disk_areas_xl[mda2].size))
mda2 = 0;
log_debug("%s: Preparing PV label header %s size %" PRIu64 " with"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s",
dev_name(lvmcache_device(info)), buffer, lvmcache_device_size(info),
(da1 > -1) ? " da1 (" : "",
(da1 > -1) ? 1 : 0,
(da1 > -1) ? xlate64(pvhdr->disk_areas_xl[da1].offset) >> SECTOR_SHIFT : 0,
(da1 > -1) ? "s, " : "",
(da1 > -1) ? 1 : 0,
(da1 > -1) ? xlate64(pvhdr->disk_areas_xl[da1].size) >> SECTOR_SHIFT : 0,
(da1 > -1) ? "s)" : "",
mda1 ? " mda1 (" : "",
mda1 ? 1 : 0,
mda1 ? xlate64(pvhdr->disk_areas_xl[mda1].offset) >> SECTOR_SHIFT : 0,
mda1 ? "s, " : "",
mda1 ? 1 : 0,
mda1 ? xlate64(pvhdr->disk_areas_xl[mda1].size) >> SECTOR_SHIFT : 0,
mda1 ? "s)" : "",
mda2 ? " mda2 (" : "",
mda2 ? 1 : 0,
mda2 ? xlate64(pvhdr->disk_areas_xl[mda2].offset) >> SECTOR_SHIFT : 0,
mda2 ? "s, " : "",
mda2 ? 1 : 0,
mda2 ? xlate64(pvhdr->disk_areas_xl[mda2].size) >> SECTOR_SHIFT : 0,
mda2 ? "s)" : "");
log_debug_metadata("%s: Preparing PV label header %s size %" PRIu64 " with"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s"
"%s%.*" PRIu64 "%s%.*" PRIu64 "%s",
dev_name(lvmcache_device(info)), buffer, lvmcache_device_size(info),
(da1 > -1) ? " da1 (" : "",
(da1 > -1) ? 1 : 0,
(da1 > -1) ? xlate64(pvhdr->disk_areas_xl[da1].offset) >> SECTOR_SHIFT : 0,
(da1 > -1) ? "s, " : "",
(da1 > -1) ? 1 : 0,
(da1 > -1) ? xlate64(pvhdr->disk_areas_xl[da1].size) >> SECTOR_SHIFT : 0,
(da1 > -1) ? "s)" : "",
mda1 ? " mda1 (" : "",
mda1 ? 1 : 0,
mda1 ? xlate64(pvhdr->disk_areas_xl[mda1].offset) >> SECTOR_SHIFT : 0,
mda1 ? "s, " : "",
mda1 ? 1 : 0,
mda1 ? xlate64(pvhdr->disk_areas_xl[mda1].size) >> SECTOR_SHIFT : 0,
mda1 ? "s)" : "",
mda2 ? " mda2 (" : "",
mda2 ? 1 : 0,
mda2 ? xlate64(pvhdr->disk_areas_xl[mda2].offset) >> SECTOR_SHIFT : 0,
mda2 ? "s, " : "",
mda2 ? 1 : 0,
mda2 ? xlate64(pvhdr->disk_areas_xl[mda2].size) >> SECTOR_SHIFT : 0,
mda2 ? "s)" : "");
if (da1 < 0) {
log_error(INTERNAL_ERROR "%s label header currently requires "
@ -294,9 +294,9 @@ static int _update_mda(struct metadata_area *mda, void *baton)
mda_set_ignored(mda, rlocn_is_ignored(mdah->raw_locns));
if (mda_is_ignored(mda)) {
log_debug("Ignoring mda on device %s at offset %"PRIu64,
dev_name(mdac->area.dev),
mdac->area.start);
log_debug_metadata("Ignoring mda on device %s at offset %"PRIu64,
dev_name(mdac->area.dev),
mdac->area.start);
if (!dev_close(mdac->area.dev))
stack;
return 1;

View File

@ -112,7 +112,7 @@ static struct labeller *_find_labeller(struct device *dev, char *buf,
if (!dev_read(dev, scan_sector << SECTOR_SHIFT,
LABEL_SCAN_SIZE, readbuf)) {
log_debug("%s: Failed to read label area", dev_name(dev));
log_debug_devs("%s: Failed to read label area", dev_name(dev));
goto out;
}
@ -208,7 +208,7 @@ int label_remove(struct device *dev)
dev_flush(dev);
if (!dev_read(dev, UINT64_C(0), LABEL_SCAN_SIZE, readbuf)) {
log_debug("%s: Failed to read label area", dev_name(dev));
log_debug_devs("%s: Failed to read label area", dev_name(dev));
goto out;
}
@ -263,7 +263,7 @@ int label_read(struct device *dev, struct label **result,
int r = 0;
if ((info = lvmcache_info_from_pvid(dev->pvid, 1))) {
log_debug("Using cached label for %s", dev_name(dev));
log_debug_devs("Using cached label for %s", dev_name(dev));
*result = lvmcache_get_label(info);
return 1;
}
@ -329,7 +329,7 @@ int label_write(struct device *dev, struct label *label)
PRIu32 ".", dev_name(dev), label->sector,
xlate32(lh->offset_xl));
if (!dev_write(dev, label->sector << SECTOR_SHIFT, LABEL_SIZE, buf)) {
log_debug("Failed to write label to %s", dev_name(dev));
log_debug_devs("Failed to write label to %s", dev_name(dev));
r = 0;
}

View File

@ -560,8 +560,8 @@ int query_resource(const char *resource, int *mode)
if (decode_lock_type(response[i].response) > *mode)
*mode = decode_lock_type(response[i].response);
log_debug("Lock held for %s, node %s : %s", resource,
response[i].node, response[i].response);
log_debug_locking("Lock held for %s, node %s : %s", resource,
response[i].node, response[i].response);
}
_cluster_free_request(response, num_responses);

View File

@ -48,7 +48,7 @@ static void _undo_flock(const char *file, int fd)
{
struct stat buf1, buf2;
log_debug("_undo_flock %s", file);
log_debug_locking("_undo_flock %s", file);
if (!flock(fd, LOCK_NB | LOCK_EX) &&
!stat(file, &buf1) &&
!fstat(fd, &buf2) &&
@ -137,8 +137,8 @@ static int _do_flock(const char *file, int *fd, int operation, uint32_t nonblock
int old_errno;
struct stat buf1, buf2;
log_debug("_do_flock %s %c%c",
file, operation == LOCK_EX ? 'W' : 'R', nonblock ? ' ' : 'B');
log_debug_locking("_do_flock %s %c%c", file,
operation == LOCK_EX ? 'W' : 'R', nonblock ? ' ' : 'B');
do {
if ((*fd > -1) && close(*fd))
log_sys_error("close", file);

View File

@ -426,7 +426,7 @@ int lock_vol(struct cmd_context *cmd, const char *vol, uint32_t flags)
if (flags == LCK_NONE) {
log_debug(INTERNAL_ERROR "%s: LCK_NONE lock requested", vol);
log_debug_locking(INTERNAL_ERROR "%s: LCK_NONE lock requested", vol);
return 1;
}

View File

@ -1039,8 +1039,8 @@ static int _log_parallel_areas(struct dm_pool *mem, struct dm_list *parallel_are
}
pvnames = dm_pool_end_object(mem);
log_debug("Parallel PVs at LE %" PRIu32 " length %" PRIu32 ": %s",
spvs->le, spvs->len, pvnames);
log_debug_alloc("Parallel PVs at LE %" PRIu32 " length %" PRIu32 ": %s",
spvs->le, spvs->len, pvnames);
dm_pool_free(mem, pvnames);
}
@ -1168,12 +1168,12 @@ static int _alloc_parallel_area(struct alloc_handle *ah, uint32_t max_to_allocat
aa[s].pe = pva->start;
aa[s].len = ah->log_len;
log_debug("Allocating parallel metadata area %" PRIu32
" on %s start PE %" PRIu32
" length %" PRIu32 ".",
(s - (ah->area_count + ah->parity_count)),
pv_dev_name(aa[s].pv), aa[s].pe,
ah->log_len);
log_debug_alloc("Allocating parallel metadata area %" PRIu32
" on %s start PE %" PRIu32
" length %" PRIu32 ".",
(s - (ah->area_count + ah->parity_count)),
pv_dev_name(aa[s].pv), aa[s].pe,
ah->log_len);
consume_pv_area(pva, ah->log_len);
dm_list_add(&ah->alloced_areas[s], &aa[s].list);
@ -1187,9 +1187,9 @@ static int _alloc_parallel_area(struct alloc_handle *ah, uint32_t max_to_allocat
aa[s].pv = pva->map->pv;
aa[s].pe = pva->start;
log_debug("Allocating parallel area %" PRIu32
" on %s start PE %" PRIu32 " length %" PRIu32 ".",
s, pv_dev_name(aa[s].pv), aa[s].pe, aa[s].len);
log_debug_alloc("Allocating parallel area %" PRIu32
" on %s start PE %" PRIu32 " length %" PRIu32 ".",
s, pv_dev_name(aa[s].pv), aa[s].pe, aa[s].len);
consume_pv_area(pva, aa[s].len);
@ -1366,8 +1366,8 @@ static int _pvs_have_matching_tag(const struct dm_config_node *cling_tag_list_cn
if (!str_list_match_list(&pv1->tags, &pv2->tags, &tag_matched))
continue;
else {
log_debug("Matched allocation PV tag %s on existing %s with free space on %s.",
tag_matched, pv_dev_name(pv1), pv_dev_name(pv2));
log_debug_alloc("Matched allocation PV tag %s on existing %s with free space on %s.",
tag_matched, pv_dev_name(pv1), pv_dev_name(pv2));
return 1;
}
}
@ -1376,8 +1376,8 @@ static int _pvs_have_matching_tag(const struct dm_config_node *cling_tag_list_cn
!str_list_match_item(&pv2->tags, str))
continue;
else {
log_debug("Matched allocation PV tag %s on existing %s with free space on %s.",
str, pv_dev_name(pv1), pv_dev_name(pv2));
log_debug_alloc("Matched allocation PV tag %s on existing %s with free space on %s.",
str, pv_dev_name(pv1), pv_dev_name(pv2));
return 1;
}
}
@ -1407,11 +1407,11 @@ static int _is_contiguous(struct pv_match *pvmatch __attribute((unused)), struct
static void _reserve_area(struct pv_area_used *area_used, struct pv_area *pva, uint32_t required,
uint32_t ix_pva, uint32_t unreserved)
{
log_debug("%s allocation area %" PRIu32 " %s %s start PE %" PRIu32
" length %" PRIu32 " leaving %" PRIu32 ".",
area_used->pva ? "Changing " : "Considering",
ix_pva - 1, area_used->pva ? "to" : "as",
dev_name(pva->map->pv->dev), pva->start, required, unreserved);
log_debug_alloc("%s allocation area %" PRIu32 " %s %s start PE %" PRIu32
" length %" PRIu32 " leaving %" PRIu32 ".",
area_used->pva ? "Changing " : "Considering",
ix_pva - 1, area_used->pva ? "to" : "as",
dev_name(pva->map->pv->dev), pva->start, required, unreserved);
area_used->pva = pva;
area_used->used = required;
@ -1717,13 +1717,13 @@ static void _report_needed_allocation_space(struct alloc_handle *ah,
metadata_count = alloc_state->log_area_count_still_needed;
}
log_debug("Still need %" PRIu32 " total extents:",
parallel_area_size * parallel_areas_count + metadata_size * metadata_count);
log_debug(" %" PRIu32 " (%" PRIu32 " data/%" PRIu32
" parity) parallel areas of %" PRIu32 " extents each",
parallel_areas_count, ah->area_count, ah->parity_count, parallel_area_size);
log_debug(" %" PRIu32 " %ss of %" PRIu32 " extents each",
metadata_count, metadata_type, metadata_size);
log_debug_alloc("Still need %" PRIu32 " total extents:",
parallel_area_size * parallel_areas_count + metadata_size * metadata_count);
log_debug_alloc(" %" PRIu32 " (%" PRIu32 " data/%" PRIu32
" parity) parallel areas of %" PRIu32 " extents each",
parallel_areas_count, ah->area_count, ah->parity_count, parallel_area_size);
log_debug_alloc(" %" PRIu32 " %ss of %" PRIu32 " extents each",
metadata_count, metadata_type, metadata_size);
}
/*
* Returns 1 regardless of whether any space was found, except on error.
@ -1756,8 +1756,8 @@ static int _find_some_parallel_space(struct alloc_handle *ah, const struct alloc
ix_offset = ah->area_count;
if (alloc_parms->alloc == ALLOC_NORMAL || (alloc_parms->flags & A_CLING_TO_ALLOCED))
log_debug("Cling_to_allocated is %sset",
alloc_parms->flags & A_CLING_TO_ALLOCED ? "" : "not ");
log_debug_alloc("Cling_to_allocated is %sset",
alloc_parms->flags & A_CLING_TO_ALLOCED ? "" : "not ");
_clear_areas(alloc_state);
_reset_unreserved(pvms);
@ -1767,9 +1767,9 @@ static int _find_some_parallel_space(struct alloc_handle *ah, const struct alloc
/* ix holds the number of areas found on other PVs */
do {
if (log_iteration_count) {
log_debug("Found %u areas for %" PRIu32 " parallel areas and %" PRIu32 " log areas so far.", ix, devices_needed, alloc_state->log_area_count_still_needed);
log_debug_alloc("Found %u areas for %" PRIu32 " parallel areas and %" PRIu32 " log areas so far.", ix, devices_needed, alloc_state->log_area_count_still_needed);
} else if (iteration_count)
log_debug("Filled %u out of %u preferred areas so far.", preferred_count, ix_offset);
log_debug_alloc("Filled %u out of %u preferred areas so far.", preferred_count, ix_offset);
/*
* Provide for escape from the loop if no progress is made.
@ -1889,12 +1889,12 @@ static int _find_some_parallel_space(struct alloc_handle *ah, const struct alloc
/* Sort the areas so we allocate from the biggest */
if (log_iteration_count) {
if (ix > devices_needed + 1) {
log_debug("Sorting %u log areas", ix - devices_needed);
log_debug_alloc("Sorting %u log areas", ix - devices_needed);
qsort(alloc_state->areas + devices_needed, ix - devices_needed, sizeof(*alloc_state->areas),
_comp_area);
}
} else if (ix > 1) {
log_debug("Sorting %u areas", ix);
log_debug_alloc("Sorting %u areas", ix);
qsort(alloc_state->areas + ix_offset, ix, sizeof(*alloc_state->areas),
_comp_area);
}
@ -2107,7 +2107,7 @@ static int _allocate(struct alloc_handle *ah,
if (alloc == ALLOC_CLING_BY_TAGS && !ah->cling_tag_list_cn)
continue;
old_allocated = alloc_state.allocated;
log_debug("Trying allocation using %s policy.", get_alloc_string(alloc));
log_debug_alloc("Trying allocation using %s policy.", get_alloc_string(alloc));
if (!_sufficient_pes_free(ah, pvms, alloc_state.allocated, ah->new_extents))
goto_out;
@ -3273,7 +3273,7 @@ void lv_set_visible(struct logical_volume *lv)
lv->status |= VISIBLE_LV;
log_debug("LV %s in VG %s is now visible.", lv->name, lv->vg->name);
log_debug_metadata("LV %s in VG %s is now visible.", lv->name, lv->vg->name);
}
void lv_set_hidden(struct logical_volume *lv)
@ -3283,7 +3283,7 @@ void lv_set_hidden(struct logical_volume *lv)
lv->status &= ~VISIBLE_LV;
log_debug("LV %s in VG %s is now hidden.", lv->name, lv->vg->name);
log_debug_metadata("LV %s in VG %s is now hidden.", lv->name, lv->vg->name);
}
int lv_remove_single(struct cmd_context *cmd, struct logical_volume *lv,
@ -3999,10 +3999,10 @@ static int _match_seg_area_to_pe_range(struct lv_segment *seg, uint32_t s,
continue;
/* FIXME Missing context in this message - add LV/seg details */
log_debug("Matched PE range %s:%" PRIu32 "-%" PRIu32 " against "
"%s %" PRIu32 " len %" PRIu32, dev_name(pvl->pv->dev),
per->start, per_end, dev_name(seg_dev(seg, s)),
seg_pe(seg, s), seg->area_len);
log_debug_alloc("Matched PE range %s:%" PRIu32 "-%" PRIu32 " against "
"%s %" PRIu32 " len %" PRIu32, dev_name(pvl->pv->dev),
per->start, per_end, dev_name(seg_dev(seg, s)),
seg_pe(seg, s), seg->area_len);
return 1;
}

View File

@ -474,9 +474,9 @@ static int _lv_split_segment(struct logical_volume *lv, struct lv_segment *seg,
if (!set_lv_segment_area_lv(split_seg, s, seg_lv(seg, s),
seg_le(seg, s) + seg->area_len, 0))
return_0;
log_debug("Split %s:%u[%u] at %u: %s LE %u", lv->name,
seg->le, s, le, seg_lv(seg, s)->name,
seg_le(split_seg, s));
log_debug_alloc("Split %s:%u[%u] at %u: %s LE %u", lv->name,
seg->le, s, le, seg_lv(seg, s)->name,
seg_le(split_seg, s));
break;
case AREA_PV:
@ -488,10 +488,10 @@ static int _lv_split_segment(struct logical_volume *lv, struct lv_segment *seg,
seg->area_len,
split_seg, s)))
return_0;
log_debug("Split %s:%u[%u] at %u: %s PE %u", lv->name,
seg->le, s, le,
dev_name(seg_dev(seg, s)),
seg_pe(split_seg, s));
log_debug_alloc("Split %s:%u[%u] at %u: %s PE %u", lv->name,
seg->le, s, le,
dev_name(seg_dev(seg, s)),
seg_pe(split_seg, s));
break;
case AREA_UNASSIGNED:

View File

@ -1078,7 +1078,7 @@ static dm_bitset_t _bitset_with_random_bits(struct dm_pool *mem, uint32_t num_bi
return NULL;
}
log_debug("Selected %" PRIu32 " random bits from %" PRIu32 ": %s", num_set_bits, num_bits, (char *) dm_pool_end_object(mem));
log_debug_metadata("Selected %" PRIu32 " random bits from %" PRIu32 ": %s", num_set_bits, num_bits, (char *) dm_pool_end_object(mem));
return bs;
}
@ -1090,9 +1090,9 @@ static int _vg_ignore_mdas(struct volume_group *vg, uint32_t num_to_ignore)
dm_bitset_t mda_to_ignore_bs;
int r = 1;
log_debug("Adjusting ignored mdas for %s: %" PRIu32 " of %" PRIu32 " mdas in use "
"but %" PRIu32 " required. Changing %" PRIu32 " mda.",
vg->name, mda_used_count, vg_mda_count(vg), vg_mda_copies(vg), num_to_ignore);
log_debug_metadata("Adjusting ignored mdas for %s: %" PRIu32 " of %" PRIu32 " mdas in use "
"but %" PRIu32 " required. Changing %" PRIu32 " mda.",
vg->name, mda_used_count, vg_mda_count(vg), vg_mda_copies(vg), num_to_ignore);
if (!num_to_ignore)
return 1;
@ -1131,9 +1131,9 @@ static int _vg_unignore_mdas(struct volume_group *vg, uint32_t num_to_unignore)
if (!num_to_unignore)
return 1;
log_debug("Adjusting ignored mdas for %s: %" PRIu32 " of %" PRIu32 " mdas in use "
"but %" PRIu32 " required. Changing %" PRIu32 " mda.",
vg->name, mda_used_count, mda_count, vg_mda_copies(vg), num_to_unignore);
log_debug_metadata("Adjusting ignored mdas for %s: %" PRIu32 " of %" PRIu32 " mdas in use "
"but %" PRIu32 " required. Changing %" PRIu32 " mda.",
vg->name, mda_used_count, mda_count, vg_mda_copies(vg), num_to_unignore);
if (!(mda_to_unignore_bs = _bitset_with_random_bits(vg->vgmem, mda_free_count,
num_to_unignore, &vg->cmd->rand_seed)))
@ -2247,7 +2247,7 @@ void lv_calculate_readahead(const struct logical_volume *lv, uint32_t *read_ahea
_lv_postorder((struct logical_volume *)lv, _lv_read_ahead_single, &_read_ahead);
if (read_ahead) {
log_debug("Calculated readahead of LV %s is %u", lv->name, _read_ahead);
log_debug_metadata("Calculated readahead of LV %s is %u", lv->name, _read_ahead);
*read_ahead = _read_ahead;
}
}
@ -3104,7 +3104,7 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
return_NULL;
}
log_debug("Empty mda found for VG %s.", vgname);
log_debug_metadata("Empty mda found for VG %s.", vgname);
if (inconsistent_mdas)
continue;
@ -3120,8 +3120,8 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
/* If the check passed, let's update VG and recalculate pvids */
if (!inconsistent_pvs) {
log_debug("Updating cache for PVs without mdas "
"in VG %s.", vgname);
log_debug_metadata("Updating cache for PVs without mdas "
"in VG %s.", vgname);
/*
* If there is no precommitted metadata, committed metadata
* is read and stored in the cache even if use_precommitted is set
@ -3138,8 +3138,8 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
fid->ref_count++;
if (dm_list_size(&correct_vg->pvs) !=
dm_list_size(pvids) + vg_missing_pv_count(correct_vg)) {
log_debug("Cached VG %s had incorrect PV list",
vgname);
log_debug_metadata("Cached VG %s had incorrect PV list",
vgname);
if (critical_section())
inconsistent = 1;
@ -3151,8 +3151,8 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
if (is_missing_pv(pvl->pv))
continue;
if (!str_list_match_item(pvids, pvl->pv->dev->pvid)) {
log_debug("Cached VG %s had incorrect PV list",
vgname);
log_debug_metadata("Cached VG %s had incorrect PV list",
vgname);
release_vg(correct_vg);
correct_vg = NULL;
break;
@ -3287,7 +3287,7 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
*/
dm_list_iterate_items(mda, &fid->metadata_areas_in_use) {
if (mda->status & MDA_INCONSISTENT) {
log_debug("Checking inconsistent MDA: %s", dev_name(mda_get_device(mda)));
log_debug_metadata("Checking inconsistent MDA: %s", dev_name(mda_get_device(mda)));
dm_list_iterate_items(pvl, &correct_vg->pvs) {
if (mda_get_device(mda) == pvl->pv->dev &&
(pvl->pv->status & MISSING_PV))
@ -4471,10 +4471,10 @@ void mda_set_ignored(struct metadata_area *mda, unsigned mda_ignored)
else
return; /* No change */
log_debug("%s ignored flag for mda %s at offset %" PRIu64 ".",
mda_ignored ? "Setting" : "Clearing",
mda->ops->mda_metadata_locn_name ? mda->ops->mda_metadata_locn_name(locn) : "",
mda->ops->mda_metadata_locn_offset ? mda->ops->mda_metadata_locn_offset(locn) : UINT64_C(0));
log_debug_metadata("%s ignored flag for mda %s at offset %" PRIu64 ".",
mda_ignored ? "Setting" : "Clearing",
mda->ops->mda_metadata_locn_name ? mda->ops->mda_metadata_locn_name(locn) : "",
mda->ops->mda_metadata_locn_offset ? mda->ops->mda_metadata_locn_offset(locn) : UINT64_C(0));
}
int mdas_empty_or_ignored(struct dm_list *mdas)

View File

@ -232,8 +232,8 @@ int discard_pv_segment(struct pv_segment *peg, uint32_t discard_area_reduction)
discard_area_reduction--;
}
log_debug("Discarding %" PRIu32 " extents offset %" PRIu64 " sectors on %s.",
discard_area_reduction, discard_offset_sectors, dev_name(peg->pv->dev));
log_debug_alloc("Discarding %" PRIu32 " extents offset %" PRIu64 " sectors on %s.",
discard_area_reduction, discard_offset_sectors, dev_name(peg->pv->dev));
if (discard_area_reduction &&
!dev_discard_blocks(peg->pv->dev, discard_offset_sectors << SECTOR_SHIFT,
discard_area_reduction * (uint64_t) peg->pv->vg->extent_size * SECTOR_SIZE))
@ -344,10 +344,10 @@ int check_pv_segments(struct volume_group *vg)
s = peg->lv_area;
/* FIXME Remove this next line eventually */
log_debug("%s %u: %6u %6u: %s(%u:%u)",
pv_dev_name(pv), segno++, peg->pe, peg->len,
peg->lvseg ? peg->lvseg->lv->name : "NULL",
peg->lvseg ? peg->lvseg->le : 0, s);
log_debug_alloc("%s %u: %6u %6u: %s(%u:%u)",
pv_dev_name(pv), segno++, peg->pe, peg->len,
peg->lvseg ? peg->lvseg->lv->name : "NULL",
peg->lvseg ? peg->lvseg->le : 0, s);
/* FIXME Add details here on failure instead */
if (start_pe != peg->pe) {
log_error("Gap in pvsegs: %u, %u",

View File

@ -50,8 +50,8 @@ static int _create_single_area(struct dm_pool *mem, struct pv_map *pvm,
if (!(pva = dm_pool_zalloc(mem, sizeof(*pva))))
return_0;
log_debug("Allowing allocation on %s start PE %" PRIu32 " length %"
PRIu32, pv_dev_name(pvm->pv), start, length);
log_debug_alloc("Allowing allocation on %s start PE %" PRIu32 " length %"
PRIu32, pv_dev_name(pvm->pv), start, length);
pva->map = pvm;
pva->start = start;
pva->count = length;

View File

@ -161,12 +161,12 @@ static int _lv_is_on_pvs(struct logical_volume *lv, struct dm_list *pvs)
dm_list_iterate_items(pvl, pvs)
if (_lv_is_on_pv(lv, pvl->pv)) {
log_debug("%s is on %s", lv->name,
pv_dev_name(pvl->pv));
log_debug_metadata("%s is on %s", lv->name,
pv_dev_name(pvl->pv));
return 1;
} else
log_debug("%s is not on %s", lv->name,
pv_dev_name(pvl->pv));
log_debug_metadata("%s is not on %s", lv->name,
pv_dev_name(pvl->pv));
return 0;
}
@ -182,8 +182,8 @@ static int _get_pv_list_for_lv(struct logical_volume *lv, struct dm_list *pvs)
return 0;
}
log_debug("Getting list of PVs that %s/%s is on:",
lv->vg->name, lv->name);
log_debug_metadata("Getting list of PVs that %s/%s is on:",
lv->vg->name, lv->name);
dm_list_iterate_items(seg, &lv->segments) {
for (s = 0; s < seg->area_count; s++) {
@ -200,8 +200,8 @@ static int _get_pv_list_for_lv(struct logical_volume *lv, struct dm_list *pvs)
}
pvl->pv = seg_pv(seg, s);
log_debug(" %s/%s is on %s", lv->vg->name, lv->name,
pv_dev_name(pvl->pv));
log_debug_metadata(" %s/%s is on %s", lv->vg->name, lv->name,
pv_dev_name(pvl->pv));
dm_list_add(pvs, &pvl->list);
}
}
@ -340,7 +340,7 @@ static int _clear_lvs(struct dm_list *lv_list)
struct volume_group *vg = NULL;
if (dm_list_empty(lv_list)) {
log_debug(INTERNAL_ERROR "Empty list of LVs given for clearing");
log_debug_metadata(INTERNAL_ERROR "Empty list of LVs given for clearing");
return 1;
}
@ -774,8 +774,8 @@ to be left for these sub-lvs.
/* Set segment areas for metadata sub_lvs */
dm_list_iterate_items(lvl, &meta_lvs) {
log_debug("Adding %s to %s",
lvl->lv->name, lv->name);
log_debug_metadata("Adding %s to %s",
lvl->lv->name, lv->name);
lvl->lv->status &= status_mask;
first_seg(lvl->lv)->status &= status_mask;
if (!set_lv_segment_area_lv(seg, s, lvl->lv, 0,
@ -791,8 +791,8 @@ to be left for these sub-lvs.
/* Set segment areas for data sub_lvs */
dm_list_iterate_items(lvl, &data_lvs) {
log_debug("Adding %s to %s",
lvl->lv->name, lv->name);
log_debug_metadata("Adding %s to %s",
lvl->lv->name, lv->name);
lvl->lv->status &= status_mask;
first_seg(lvl->lv)->status &= status_mask;
if (!set_lv_segment_area_lv(seg, s, lvl->lv, 0,
@ -1468,8 +1468,8 @@ static int _convert_mirror_to_raid1(struct logical_volume *lv,
}
for (s = 0; s < seg->area_count; s++) {
log_debug("Allocating new metadata LV for %s",
seg_lv(seg, s)->name);
log_debug_metadata("Allocating new metadata LV for %s",
seg_lv(seg, s)->name);
if (!_alloc_rmeta_for_lv(seg_lv(seg, s), &(lvl_array[s].lv))) {
log_error("Failed to allocate metadata LV for %s in %s",
seg_lv(seg, s)->name, lv->name);
@ -1478,14 +1478,14 @@ static int _convert_mirror_to_raid1(struct logical_volume *lv,
dm_list_add(&meta_lvs, &(lvl_array[s].list));
}
log_debug("Clearing newly allocated metadata LVs");
log_debug_metadata("Clearing newly allocated metadata LVs");
if (!_clear_lvs(&meta_lvs)) {
log_error("Failed to initialize metadata LVs");
return 0;
}
if (seg->log_lv) {
log_debug("Removing mirror log, %s", seg->log_lv->name);
log_debug_metadata("Removing mirror log, %s", seg->log_lv->name);
if (!remove_mirror_log(lv->vg->cmd, lv, NULL, 0)) {
log_error("Failed to remove mirror log");
return 0;
@ -1496,7 +1496,7 @@ static int _convert_mirror_to_raid1(struct logical_volume *lv,
s = 0;
dm_list_iterate_items(lvl, &meta_lvs) {
log_debug("Adding %s to %s", lvl->lv->name, lv->name);
log_debug_metadata("Adding %s to %s", lvl->lv->name, lv->name);
/* Images are known to be in-sync */
lvl->lv->status &= ~LV_REBUILD;
@ -1524,14 +1524,14 @@ static int _convert_mirror_to_raid1(struct logical_volume *lv,
}
sprintf(new_name, "%s_rimage_%u", lv->name, s);
log_debug("Renaming %s to %s", seg_lv(seg, s)->name, new_name);
log_debug_metadata("Renaming %s to %s", seg_lv(seg, s)->name, new_name);
seg_lv(seg, s)->name = new_name;
seg_lv(seg, s)->status &= ~MIRROR_IMAGE;
seg_lv(seg, s)->status |= RAID_IMAGE;
}
init_mirror_in_sync(1);
log_debug("Setting new segtype for %s", lv->name);
log_debug_metadata("Setting new segtype for %s", lv->name);
seg->segtype = new_segtype;
lv->status &= ~MIRRORED;
lv->status |= RAID;

View File

@ -568,7 +568,7 @@ int cmd_vg_read(struct cmd_context *cmd, struct dm_list *cmd_vgs)
dm_list_iterate_items(cvl, cmd_vgs) {
cvl->vg = vg_read(cmd, cvl->vg_name, cvl->vgid, cvl->flags);
if (vg_read_error(cvl->vg)) {
log_debug("Failed to vg_read %s", cvl->vg_name);
log_debug_metadata("Failed to vg_read %s", cvl->vg_name);
return 0;
}
cvl->vg->cmd_vgs = cmd_vgs; /* Make it usable in VG */
@ -621,7 +621,7 @@ int find_replicator_vgs(struct logical_volume *lv)
break;
}
log_debug("VG: %s added as missing.", rsite->vg_name);
log_debug_metadata("VG: %s added as missing.", rsite->vg_name);
lv->vg->cmd_missing_vgs++;
}

View File

@ -89,8 +89,8 @@ int detach_pool_lv(struct lv_segment *seg)
case DM_THIN_MESSAGE_CREATE_SNAP:
case DM_THIN_MESSAGE_CREATE_THIN:
if (tmsg->u.lv == seg->lv) {
log_debug("Discarding message for LV %s.",
tmsg->u.lv->name);
log_debug_metadata("Discarding message for LV %s.",
tmsg->u.lv->name);
dm_list_del(&tmsg->list);
no_update = 1; /* Replacing existing */
}
@ -186,10 +186,10 @@ int attach_pool_message(struct lv_segment *pool_seg, dm_thin_message_t type,
dm_list_add(&pool_seg->thin_messages, &tmsg->list);
log_debug("Added %s message",
(type == DM_THIN_MESSAGE_CREATE_SNAP ||
type == DM_THIN_MESSAGE_CREATE_THIN) ? "create" :
(type == DM_THIN_MESSAGE_DELETE) ? "delete" : "unknown");
log_debug_metadata("Added %s message",
(type == DM_THIN_MESSAGE_CREATE_SNAP ||
type == DM_THIN_MESSAGE_CREATE_THIN) ? "create" :
(type == DM_THIN_MESSAGE_DELETE) ? "delete" : "unknown");
return 1;
}
@ -306,7 +306,7 @@ uint32_t get_free_pool_device_id(struct lv_segment *thin_pool_seg)
return 0;
}
log_debug("Found free pool device_id %u.", max_id);
log_debug_metadata("Found free pool device_id %u.", max_id);
return max_id;
}

View File

@ -56,7 +56,7 @@ struct volume_group *alloc_vg(const char *pool_name, struct cmd_context *cmd,
dm_list_init(&vg->tags);
dm_list_init(&vg->removed_pvs);
log_debug("Allocated VG %s at %p.", vg->name, vg);
log_debug_mem("Allocated VG %s at %p.", vg->name, vg);
return vg;
}
@ -71,7 +71,7 @@ static void _free_vg(struct volume_group *vg)
return;
}
log_debug("Freeing VG %s at %p.", vg->name, vg);
log_debug_mem("Freeing VG %s at %p.", vg->name, vg);
dm_hash_destroy(vg->hostnames);
dm_pool_destroy(vg->vgmem);
@ -260,8 +260,8 @@ int vg_set_mda_copies(struct volume_group *vg, uint32_t mda_copies)
vg->mda_copies = mda_copies;
/* FIXME Use log_verbose when this is due to specific cmdline request. */
log_debug("Setting mda_copies to %"PRIu32" for VG %s",
mda_copies, vg->name);
log_debug_metadata("Setting mda_copies to %"PRIu32" for VG %s",
mda_copies, vg->name);
return 1;
}

View File

@ -187,7 +187,7 @@ static int _mirrored_target_percent(void **target_state,
*target_state = _mirrored_init_target(mem, cmd);
/* Status line: <#mirrors> (maj:min)+ <synced>/<total_regions> */
log_debug("Mirror status: %s", params);
log_debug_activation("Mirror status: %s", params);
if (sscanf(pos, "%u %n", &mirror_count, &used) != 1) {
log_error("Failure parsing mirror status mirror count: %s",
@ -288,7 +288,7 @@ static int _mirrored_transient_status(struct lv_segment *seg, char *params)
log->name);
return 0;
}
log_debug("Found mirror log at %d:%d", info.major, info.minor);
log_debug_activation("Found mirror log at %d:%d", info.major, info.minor);
sprintf(buf, "%d:%d", info.major, info.minor);
if (strcmp(buf, log_args[1])) {
log_error("Mirror log mismatch. Metadata says %s, kernel says %s.",
@ -312,11 +312,11 @@ static int _mirrored_transient_status(struct lv_segment *seg, char *params)
seg_lv(seg, i)->name);
return 0;
}
log_debug("Found mirror image at %d:%d", info.major, info.minor);
log_debug_activation("Found mirror image at %d:%d", info.major, info.minor);
sprintf(buf, "%d:%d", info.major, info.minor);
for (j = 0; j < num_devs; ++j) {
if (!strcmp(buf, args[j])) {
log_debug("Match: metadata image %d matches kernel image %d", i, j);
log_debug_activation("Match: metadata image %d matches kernel image %d", i, j);
images[j] = seg_lv(seg, i);
}
}

View File

@ -136,9 +136,9 @@ void init_is_static(unsigned value)
void init_udev_checking(int checking)
{
if ((_udev_checking = checking))
log_debug("LVM udev checking enabled");
log_debug_activation("LVM udev checking enabled");
else
log_debug("LVM udev checking disabled");
log_debug_activation("LVM udev checking disabled");
}
void init_retry_deactivation(int retry)
@ -149,9 +149,9 @@ void init_retry_deactivation(int retry)
void init_activation_checks(int checks)
{
if ((_activation_checks = checks))
log_debug("LVM activation checks enabled");
log_debug_activation("LVM activation checks enabled");
else
log_debug("LVM activation checks disabled");
log_debug_activation("LVM activation checks disabled");
}
void init_dev_disable_after_error_count(int value)

View File

@ -46,12 +46,12 @@ int udev_is_running(void)
int r;
if (!_udev) {
log_debug(_no_context_msg);
log_debug_activation(_no_context_msg);
goto bad;
}
if (!(udev_queue = udev_queue_new(_udev))) {
log_debug("Could not get udev state.");
log_debug_activation("Could not get udev state.");
goto bad;
}
@ -61,7 +61,7 @@ int udev_is_running(void)
return r;
bad:
log_debug("Assuming udev is not running.");
log_debug_activation("Assuming udev is not running.");
return 0;
}

View File

@ -171,15 +171,15 @@ static int _maps_line(const struct dm_config_node *cn, lvmlock_t lock,
/* Select readable maps */
if (fr != 'r') {
log_debug("%s area unreadable %s : Skipping.", lock_str, line);
log_debug_mem("%s area unreadable %s : Skipping.", lock_str, line);
return 1;
}
/* always ignored areas */
for (i = 0; i < sizeof(_ignore_maps) / sizeof(_ignore_maps[0]); ++i)
if (strstr(line + pos, _ignore_maps[i])) {
log_debug("%s ignore filter '%s' matches '%s': Skipping.",
lock_str, _ignore_maps[i], line);
log_debug_mem("%s ignore filter '%s' matches '%s': Skipping.",
lock_str, _ignore_maps[i], line);
return 1;
}
@ -188,8 +188,8 @@ static int _maps_line(const struct dm_config_node *cn, lvmlock_t lock,
/* If no blacklist configured, use an internal set */
for (i = 0; i < sizeof(_blacklist_maps) / sizeof(_blacklist_maps[0]); ++i)
if (strstr(line + pos, _blacklist_maps[i])) {
log_debug("%s default filter '%s' matches '%s': Skipping.",
lock_str, _blacklist_maps[i], line);
log_debug_mem("%s default filter '%s' matches '%s': Skipping.",
lock_str, _blacklist_maps[i], line);
return 1;
}
} else {
@ -197,8 +197,8 @@ static int _maps_line(const struct dm_config_node *cn, lvmlock_t lock,
if ((cv->type != DM_CFG_STRING) || !cv->v.str[0])
continue;
if (strstr(line + pos, cv->v.str)) {
log_debug("%s_filter '%s' matches '%s': Skipping.",
lock_str, cv->v.str, line);
log_debug_mem("%s_filter '%s' matches '%s': Skipping.",
lock_str, cv->v.str, line);
return 1;
}
}
@ -213,8 +213,8 @@ static int _maps_line(const struct dm_config_node *cn, lvmlock_t lock,
#endif
*mstats += sz;
log_debug("%s %10ldKiB %12lx - %12lx %c%c%c%c%s", lock_str,
((long)sz + 1023) / 1024, from, to, fr, fw, fx, fp, line + pos);
log_debug_mem("%s %10ldKiB %12lx - %12lx %c%c%c%c%s", lock_str,
((long)sz + 1023) / 1024, from, to, fr, fw, fx, fp, line + pos);
if (lock == LVM_MLOCK) {
if (mlock((const void*)from, sz) < 0) {
@ -299,8 +299,8 @@ static int _memlock_maps(struct cmd_context *cmd, lvmlock_t lock, size_t *mstats
line = line_end + 1;
}
log_debug("%socked %ld bytes",
(lock == LVM_MLOCK) ? "L" : "Unl", (long)*mstats);
log_debug_mem("%socked %ld bytes",
(lock == LVM_MLOCK) ? "L" : "Unl", (long)*mstats);
return ret;
}
@ -367,8 +367,8 @@ static void _unlock_mem(struct cmd_context *cmd)
(long)_mstats, (long)unlock_mstats);
else
/* FIXME Believed due to incorrect use of yes_no_prompt while locks held */
log_debug("Suppressed internal error: Maps lock %ld < unlock %ld, a one-page difference.",
(long)_mstats, (long)unlock_mstats);
log_debug_mem("Suppressed internal error: Maps lock %ld < unlock %ld, a one-page difference.",
(long)_mstats, (long)unlock_mstats);
}
}
@ -380,8 +380,8 @@ static void _unlock_mem(struct cmd_context *cmd)
static void _lock_mem_if_needed(struct cmd_context *cmd)
{
log_debug("Lock: Memlock counters: locked:%d critical:%d daemon:%d suspended:%d",
_mem_locked, _critical_section, _memlock_count_daemon, dm_get_suspended_counter());
log_debug_mem("Lock: Memlock counters: locked:%d critical:%d daemon:%d suspended:%d",
_mem_locked, _critical_section, _memlock_count_daemon, dm_get_suspended_counter());
if (!_mem_locked &&
((_critical_section + _memlock_count_daemon) == 1)) {
_mem_locked = 1;
@ -391,8 +391,8 @@ static void _lock_mem_if_needed(struct cmd_context *cmd)
static void _unlock_mem_if_possible(struct cmd_context *cmd)
{
log_debug("Unlock: Memlock counters: locked:%d critical:%d daemon:%d suspended:%d",
_mem_locked, _critical_section, _memlock_count_daemon, dm_get_suspended_counter());
log_debug_mem("Unlock: Memlock counters: locked:%d critical:%d daemon:%d suspended:%d",
_mem_locked, _critical_section, _memlock_count_daemon, dm_get_suspended_counter());
if (_mem_locked &&
!_critical_section &&
!_memlock_count_daemon) {
@ -405,7 +405,7 @@ void critical_section_inc(struct cmd_context *cmd, const char *reason)
{
if (!_critical_section) {
_critical_section = 1;
log_debug("Entering critical section (%s).", reason);
log_debug_mem("Entering critical section (%s).", reason);
}
_lock_mem_if_needed(cmd);
@ -415,7 +415,7 @@ void critical_section_dec(struct cmd_context *cmd, const char *reason)
{
if (_critical_section && !dm_get_suspended_counter()) {
_critical_section = 0;
log_debug("Leaving critical section (%s).", reason);
log_debug_mem("Leaving critical section (%s).", reason);
}
}
@ -436,7 +436,7 @@ void memlock_inc_daemon(struct cmd_context *cmd)
++_memlock_count_daemon;
if (_memlock_count_daemon == 1 && _critical_section > 0)
log_error(INTERNAL_ERROR "_memlock_inc_daemon used in critical section.");
log_debug("memlock_count_daemon inc to %d", _memlock_count_daemon);
log_debug_mem("memlock_count_daemon inc to %d", _memlock_count_daemon);
_lock_mem_if_needed(cmd);
}
@ -445,7 +445,7 @@ void memlock_dec_daemon(struct cmd_context *cmd)
if (!_memlock_count_daemon)
log_error(INTERNAL_ERROR "_memlock_count_daemon has dropped below 0.");
--_memlock_count_daemon;
log_debug("memlock_count_daemon dec to %d", _memlock_count_daemon);
log_debug_mem("memlock_count_daemon dec to %d", _memlock_count_daemon);
_unlock_mem_if_possible(cmd);
}
@ -465,7 +465,7 @@ void memlock_init(struct cmd_context *cmd)
void memlock_reset(void)
{
log_debug("memlock reset.");
log_debug_mem("memlock reset.");
_mem_locked = 0;
_critical_section = 0;
_memlock_count_daemon = 0;

View File

@ -328,7 +328,7 @@ static int _thin_pool_add_target_line(struct dev_manager *dm,
return 0;
}
}
log_debug("Thin pool create_%s %s.", (!origin) ? "thin" : "snap", lmsg->u.lv->name);
log_debug_activation("Thin pool create_%s %s.", (!origin) ? "thin" : "snap", lmsg->u.lv->name);
if (!dm_tree_node_add_thin_pool_message(node,
(!origin) ? lmsg->type : DM_THIN_MESSAGE_CREATE_SNAP,
first_seg(lmsg->u.lv)->device_id,
@ -336,7 +336,7 @@ static int _thin_pool_add_target_line(struct dev_manager *dm,
return_0;
break;
case DM_THIN_MESSAGE_DELETE:
log_debug("Thin pool delete %u.", lmsg->u.delete_id);
log_debug_activation("Thin pool delete %u.", lmsg->u.delete_id);
if (!dm_tree_node_add_thin_pool_message(node,
lmsg->type,
lmsg->u.delete_id, 0))
@ -350,7 +350,7 @@ static int _thin_pool_add_target_line(struct dev_manager *dm,
if (!dm_list_empty(&seg->thin_messages)) {
/* Messages were passed, modify transaction_id as the last one */
log_debug("Thin pool set transaction id %" PRIu64 ".", seg->transaction_id);
log_debug_activation("Thin pool set transaction id %" PRIu64 ".", seg->transaction_id);
if (!dm_tree_node_add_thin_pool_message(node,
DM_THIN_MESSAGE_SET_TRANSACTION_ID,
seg->transaction_id - 1,

View File

@ -756,9 +756,9 @@ int dm_task_set_newuuid(struct dm_task *dmt, const char *newuuid)
}
if (r) {
log_debug("New device uuid mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
newuuid, mangled_uuid);
log_debug_activation("New device uuid mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
newuuid, mangled_uuid);
newuuid = mangled_uuid;
}
@ -1505,8 +1505,8 @@ static int _check_children_not_suspended_v4(struct dm_task *dmt, uint64_t device
*/
if (info.suspended) {
if (!device)
log_debug("Attempting to suspend a device that is already suspended "
"(%u:%u)", info.major, info.minor);
log_debug_activation("Attempting to suspend a device that is already suspended "
"(%u:%u)", info.major, info.minor);
else
log_error(INTERNAL_ERROR "Attempt to suspend device %s%s%s%.0d%s%.0d%s%s"
"that uses already-suspended device (%u:%u)",
@ -1584,8 +1584,8 @@ static int _do_dm_ioctl_unmangle_string(char *str, const char *str_name,
return_0;
if ((r = unmangle_string(str, str_name, strlen(str), buf, buf_size, mode)) < 0) {
log_debug("_do_dm_ioctl_unmangle_string: failed to "
"unmangle %s \"%s\"", str_name, str);
log_debug_activation("_do_dm_ioctl_unmangle_string: failed to "
"unmangle %s \"%s\"", str_name, str);
return 0;
} else if (r)
memcpy(str, buf, strlen(buf) + 1);
@ -1680,15 +1680,15 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
* libdevmapper's node and symlink creation code.
*/
if (!dmt->cookie_set && dm_udev_get_sync_support()) {
log_debug("Cookie value is not set while trying to call %s "
"ioctl. Please, consider using libdevmapper's udev "
"synchronisation interface or disable it explicitly "
"by calling dm_udev_set_sync_support(0).",
dmt->type == DM_DEVICE_RESUME ? "DM_DEVICE_RESUME" :
dmt->type == DM_DEVICE_REMOVE ? "DM_DEVICE_REMOVE" :
"DM_DEVICE_RENAME");
log_debug("Switching off device-mapper and all subsystem related "
"udev rules. Falling back to libdevmapper node creation.");
log_debug_activation("Cookie value is not set while trying to call %s "
"ioctl. Please, consider using libdevmapper's udev "
"synchronisation interface or disable it explicitly "
"by calling dm_udev_set_sync_support(0).",
dmt->type == DM_DEVICE_RESUME ? "DM_DEVICE_RESUME" :
dmt->type == DM_DEVICE_REMOVE ? "DM_DEVICE_REMOVE" :
"DM_DEVICE_RENAME");
log_debug_activation("Switching off device-mapper and all subsystem related "
"udev rules. Falling back to libdevmapper node creation.");
/*
* Disable general dm and subsystem rules but keep
* dm disk rules if not flagged out explicitly before.
@ -1700,28 +1700,28 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
}
}
log_debug("dm %s %s%s %s%s%s %s%.0d%s%.0d%s"
"%s%c%c%s%s%s%s%s%s %.0" PRIu64 " %s [%u] (*%u)",
_cmd_data_v4[dmt->type].name,
dmt->new_uuid ? "UUID " : "",
dmi->name, dmi->uuid, dmt->newname ? " " : "",
dmt->newname ? dmt->newname : "",
dmt->major > 0 ? "(" : "",
dmt->major > 0 ? dmt->major : 0,
dmt->major > 0 ? ":" : "",
dmt->minor > 0 ? dmt->minor : 0,
dmt->major > 0 && dmt->minor == 0 ? "0" : "",
dmt->major > 0 ? ") " : "",
dmt->no_open_count ? 'N' : 'O',
dmt->no_flush ? 'N' : 'F',
dmt->read_only ? "R" : "",
dmt->skip_lockfs ? "S " : "",
dmt->retry_remove ? "T " : "",
dmt->secure_data ? "W " : "",
dmt->query_inactive_table ? "I " : "",
dmt->enable_checks ? "C" : "",
dmt->sector, _sanitise_message(dmt->message),
dmi->data_size, retry_repeat_count);
log_debug_activation("dm %s %s%s %s%s%s %s%.0d%s%.0d%s"
"%s%c%c%s%s%s%s%s%s %.0" PRIu64 " %s [%u] (*%u)",
_cmd_data_v4[dmt->type].name,
dmt->new_uuid ? "UUID " : "",
dmi->name, dmi->uuid, dmt->newname ? " " : "",
dmt->newname ? dmt->newname : "",
dmt->major > 0 ? "(" : "",
dmt->major > 0 ? dmt->major : 0,
dmt->major > 0 ? ":" : "",
dmt->minor > 0 ? dmt->minor : 0,
dmt->major > 0 && dmt->minor == 0 ? "0" : "",
dmt->major > 0 ? ") " : "",
dmt->no_open_count ? 'N' : 'O',
dmt->no_flush ? 'N' : 'F',
dmt->read_only ? "R" : "",
dmt->skip_lockfs ? "S " : "",
dmt->retry_remove ? "T " : "",
dmt->secure_data ? "W " : "",
dmt->query_inactive_table ? "I " : "",
dmt->enable_checks ? "C" : "",
dmt->sector, _sanitise_message(dmt->message),
dmi->data_size, retry_repeat_count);
#ifdef DM_IOCTLS
if (ioctl(_control_fd, command, dmi) < 0 &&
dmt->expected_errno != errno) {
@ -1754,8 +1754,8 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
if (ioctl_with_uevent && dm_udev_get_sync_support() &&
!_check_uevent_generated(dmi)) {
log_debug("Uevent not generated! Calling udev_complete "
"internally to avoid process lock-up.");
log_debug_activation("Uevent not generated! Calling udev_complete "
"internally to avoid process lock-up.");
_udev_complete(dmt);
}

View File

@ -206,7 +206,7 @@ int dm_get_library_version(char *version, size_t size)
void inc_suspended(void)
{
_suspended_dev_counter++;
log_debug("Suspended device counter increased to %d", _suspended_dev_counter);
log_debug_activation("Suspended device counter increased to %d", _suspended_dev_counter);
}
void dec_suspended(void)
@ -217,7 +217,7 @@ void dec_suspended(void)
}
_suspended_dev_counter--;
log_debug("Suspended device counter reduced to %d", _suspended_dev_counter);
log_debug_activation("Suspended device counter reduced to %d", _suspended_dev_counter);
}
int dm_get_suspended_counter(void)
@ -466,8 +466,8 @@ int unmangle_string(const char *str, const char *str_name, size_t len,
if (str[i] == '\\' && str[i+1] == 'x') {
if (!sscanf(&str[i+2], "%2x%s", &code, str_rest)) {
log_debug("Hex encoding mismatch detected in %s \"%s\" "
"while trying to unmangle it.", str_name, str);
log_debug_activation("Hex encoding mismatch detected in %s \"%s\" "
"while trying to unmangle it.", str_name, str);
goto out;
}
buf[j] = (unsigned char) code;
@ -514,9 +514,9 @@ static int _dm_task_set_name(struct dm_task *dmt, const char *name,
/* Store mangled_dev_name only if it differs from dev_name! */
if (r) {
log_debug("Device name mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
name, mangled_name);
log_debug_activation("Device name mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
name, mangled_name);
if (!(dmt->mangled_dev_name = dm_strdup(mangled_name))) {
log_error("_dm_task_set_name: dm_strdup(%s) failed", mangled_name);
return 0;
@ -704,9 +704,9 @@ int dm_task_set_newname(struct dm_task *dmt, const char *newname)
}
if (r) {
log_debug("New device name mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
newname, mangled_name);
log_debug_activation("New device name mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
newname, mangled_name);
newname = mangled_name;
}
@ -742,9 +742,9 @@ int dm_task_set_uuid(struct dm_task *dmt, const char *uuid)
}
if (r) {
log_debug("Device uuid mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
uuid, mangled_uuid);
log_debug_activation("Device uuid mangled [%s]: %s --> %s",
mangling_mode == DM_STRING_MANGLING_AUTO ? "auto" : "hex",
uuid, mangled_uuid);
if (!(dmt->mangled_uuid = dm_strdup(mangled_uuid))) {
log_error("dm_task_set_uuid: dm_strdup(%s) failed", mangled_uuid);
@ -842,14 +842,14 @@ static int _selabel_lookup(const char *path, mode_t mode,
}
if (selabel_lookup(_selabel_handle, scontext, path, mode)) {
log_debug("selabel_lookup failed for %s: %s",
path, strerror(errno));
log_debug_activation("selabel_lookup failed for %s: %s",
path, strerror(errno));
return 0;
}
#else
if (matchpathcon(path, mode, scontext)) {
log_debug("matchpathcon failed for %s: %s",
path, strerror(errno));
log_debug_activation("matchpathcon failed for %s: %s",
path, strerror(errno));
return 0;
}
#endif
@ -869,10 +869,10 @@ int dm_prepare_selinux_context(const char *path, mode_t mode)
if (!_selabel_lookup(path, mode, &scontext))
return_0;
log_debug("Preparing SELinux context for %s to %s.", path, scontext);
log_debug_activation("Preparing SELinux context for %s to %s.", path, scontext);
}
else
log_debug("Resetting SELinux context to default value.");
log_debug_activation("Resetting SELinux context to default value.");
if (setfscreatecon(scontext) < 0) {
log_sys_error("setfscreatecon", path);
@ -896,7 +896,7 @@ int dm_set_selinux_context(const char *path, mode_t mode)
if (!_selabel_lookup(path, mode, &scontext))
return_0;
log_debug("Setting SELinux context for %s to %s.", path, scontext);
log_debug_activation("Setting SELinux context for %s to %s.", path, scontext);
if ((lsetfilecon(path, scontext) < 0) && (errno != ENOTSUP)) {
log_sys_error("lsetfilecon", path);
@ -969,7 +969,7 @@ static int _add_dev_node(const char *dev_name, uint32_t major, uint32_t minor,
return 0;
}
log_debug("Created %s", path);
log_debug_activation("Created %s", path);
return 1;
}
@ -992,7 +992,7 @@ static int _rm_dev_node(const char *dev_name, int warn_if_udev_failed)
return 0;
}
log_debug("Removed %s", path);
log_debug_activation("Removed %s", path);
return 1;
}
@ -1049,7 +1049,7 @@ static int _rename_dev_node(const char *old_name, const char *new_name,
return 0;
}
log_debug("Renamed %s to %s", oldpath, newpath);
log_debug_activation("Renamed %s to %s", oldpath, newpath);
return 1;
}
@ -1097,8 +1097,8 @@ int get_dev_node_read_ahead(const char *dev_name, uint32_t major, uint32_t minor
} else {
buf[len] = 0; /* kill \n and ensure \0 */
*read_ahead = atoi(buf) * 2;
log_debug("%s (%d:%d): read ahead is %" PRIu32,
dev_name, major, minor, *read_ahead);
log_debug_activation("%s (%d:%d): read ahead is %" PRIu32,
dev_name, major, minor, *read_ahead);
}
if (close(fd))
@ -1129,7 +1129,7 @@ int get_dev_node_read_ahead(const char *dev_name, uint32_t major, uint32_t minor
r = 0;
} else {
*read_ahead = (uint32_t) read_ahead_long;
log_debug("%s: read ahead is %" PRIu32, dev_name, *read_ahead);
log_debug_activation("%s: read ahead is %" PRIu32, dev_name, *read_ahead);
}
if (close(fd))
@ -1147,8 +1147,8 @@ static int _set_read_ahead(const char *dev_name, uint32_t major, uint32_t minor,
int fd;
long read_ahead_long = (long) read_ahead;
log_debug("%s (%d:%d): Setting read ahead to %" PRIu32, dev_name,
major, minor, read_ahead);
log_debug_activation("%s (%d:%d): Setting read ahead to %" PRIu32, dev_name,
major, minor, read_ahead);
/*
* If we know the device number, use sysfs if we can.
@ -1221,7 +1221,7 @@ static int _set_dev_node_read_ahead(const char *dev_name,
return_0;
if (current_read_ahead > read_ahead) {
log_debug("%s: retaining kernel read ahead of %" PRIu32
log_debug_activation("%s: retaining kernel read ahead of %" PRIu32
" (requested %" PRIu32 ")",
dev_name, current_read_ahead, read_ahead);
return 1;
@ -1332,19 +1332,19 @@ static void _log_node_op(const char *action_str, struct node_op_parms *nop)
switch (nop->type) {
case NODE_ADD:
log_debug("%s: %s NODE_ADD (%" PRIu32 ",%" PRIu32 ") %u:%u 0%o%s%s",
nop->dev_name, action_str, nop->major, nop->minor, nop->uid, nop->gid, nop->mode,
rely, verify);
log_debug_activation("%s: %s NODE_ADD (%" PRIu32 ",%" PRIu32 ") %u:%u 0%o%s%s",
nop->dev_name, action_str, nop->major, nop->minor, nop->uid, nop->gid, nop->mode,
rely, verify);
break;
case NODE_DEL:
log_debug("%s: %s NODE_DEL%s%s", nop->dev_name, action_str, rely, verify);
log_debug_activation("%s: %s NODE_DEL%s%s", nop->dev_name, action_str, rely, verify);
break;
case NODE_RENAME:
log_debug("%s: %s NODE_RENAME to %s%s%s", nop->old_name, action_str, nop->dev_name, rely, verify);
log_debug_activation("%s: %s NODE_RENAME to %s%s%s", nop->old_name, action_str, nop->dev_name, rely, verify);
break;
case NODE_READ_AHEAD:
log_debug("%s: %s NODE_READ_AHEAD %" PRIu32 " (flags=%" PRIu32 ")%s%s",
nop->dev_name, action_str, nop->read_ahead, nop->read_ahead_flags, rely, verify);
log_debug_activation("%s: %s NODE_READ_AHEAD %" PRIu32 " (flags=%" PRIu32 ")%s%s",
nop->dev_name, action_str, nop->read_ahead, nop->read_ahead_flags, rely, verify);
break;
default:
; /* NOTREACHED */
@ -1507,8 +1507,8 @@ static int _canonicalize_and_set_dir(const char *src, const char *suffix, size_t
const char *slash;
if (*src != '/') {
log_debug("Invalid directory value, %s: "
"not an absolute name.", src);
log_debug_activation("Invalid directory value, %s: "
"not an absolute name.", src);
return 0;
}
@ -1516,7 +1516,7 @@ static int _canonicalize_and_set_dir(const char *src, const char *suffix, size_t
slash = src[len-1] == '/' ? "" : "/";
if (dm_snprintf(dir, max_len, "%s%s%s", src, slash, suffix ? suffix : "") < 0) {
log_debug("Invalid directory value, %s: name too long.", src);
log_debug_activation("Invalid directory value, %s: name too long.", src);
return 0;
}
@ -1915,8 +1915,8 @@ static int _check_udev_is_running(void)
}
if (!(r = udev_queue_get_udev_is_active(udev_queue)))
log_debug("Udev is not running. "
"Not using udev synchronisation code.");
log_debug_activation("Udev is not running. "
"Not using udev synchronisation code.");
udev_queue_unref(udev_queue);
udev_unref(udev);
@ -1959,9 +1959,9 @@ int dm_udev_get_sync_support(void)
void dm_udev_set_checking(int checking)
{
if ((_udev_checking = checking))
log_debug("DM udev checking enabled");
log_debug_activation("DM udev checking enabled");
else
log_debug("DM udev checking disabled");
log_debug_activation("DM udev checking disabled");
}
int dm_udev_get_checking(void)
@ -2024,7 +2024,7 @@ static int _udev_notify_sem_inc(uint32_t cookie, int semid)
return 0;
}
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) incremented to %d",
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) incremented to %d",
cookie, semid, val);
return 1;
@ -2059,8 +2059,8 @@ static int _udev_notify_sem_dec(uint32_t cookie, int semid)
return 0;
}
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) decremented to %d",
cookie, semid, val - 1);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) decremented to %d",
cookie, semid, val - 1);
return 1;
}
@ -2074,8 +2074,8 @@ static int _udev_notify_sem_destroy(uint32_t cookie, int semid)
return 0;
}
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) destroyed", cookie,
semid);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) destroyed", cookie,
semid);
return 1;
}
@ -2132,8 +2132,8 @@ static int _udev_notify_sem_create(uint32_t *cookie, int *semid)
}
} while (!base_cookie);
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) created",
gen_cookie, gen_semid);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) created",
gen_cookie, gen_semid);
sem_arg.val = 1;
@ -2152,8 +2152,8 @@ static int _udev_notify_sem_create(uint32_t *cookie, int *semid)
goto bad;
}
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) incremented to %d",
gen_cookie, gen_semid, val);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) incremented to %d",
gen_cookie, gen_semid, val);
if (close(fd))
stack;
@ -2257,16 +2257,16 @@ int dm_task_set_cookie(struct dm_task *dmt, uint32_t *cookie, uint16_t flags)
dmt->event_nr |= ~DM_UDEV_FLAGS_MASK & *cookie;
dmt->cookie_set = 1;
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) assigned to "
"%s task(%d) with flags%s%s%s%s%s%s%s (0x%" PRIx16 ")", *cookie, semid, _task_type_disp(dmt->type), dmt->type,
(flags & DM_UDEV_DISABLE_DM_RULES_FLAG) ? " DISABLE_DM_RULES" : "",
(flags & DM_UDEV_DISABLE_SUBSYSTEM_RULES_FLAG) ? " DISABLE_SUBSYSTEM_RULES" : "",
(flags & DM_UDEV_DISABLE_DISK_RULES_FLAG) ? " DISABLE_DISK_RULES" : "",
(flags & DM_UDEV_DISABLE_OTHER_RULES_FLAG) ? " DISABLE_OTHER_RULES" : "",
(flags & DM_UDEV_LOW_PRIORITY_FLAG) ? " LOW_PRIORITY" : "",
(flags & DM_UDEV_DISABLE_LIBRARY_FALLBACK) ? " DISABLE_LIBRARY_FALLBACK" : "",
(flags & DM_UDEV_PRIMARY_SOURCE_FLAG) ? " PRIMARY_SOURCE" : "",
flags);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) assigned to "
"%s task(%d) with flags%s%s%s%s%s%s%s (0x%" PRIx16 ")", *cookie, semid, _task_type_disp(dmt->type), dmt->type,
(flags & DM_UDEV_DISABLE_DM_RULES_FLAG) ? " DISABLE_DM_RULES" : "",
(flags & DM_UDEV_DISABLE_SUBSYSTEM_RULES_FLAG) ? " DISABLE_SUBSYSTEM_RULES" : "",
(flags & DM_UDEV_DISABLE_DISK_RULES_FLAG) ? " DISABLE_DISK_RULES" : "",
(flags & DM_UDEV_DISABLE_OTHER_RULES_FLAG) ? " DISABLE_OTHER_RULES" : "",
(flags & DM_UDEV_LOW_PRIORITY_FLAG) ? " LOW_PRIORITY" : "",
(flags & DM_UDEV_DISABLE_LIBRARY_FALLBACK) ? " DISABLE_LIBRARY_FALLBACK" : "",
(flags & DM_UDEV_PRIMARY_SOURCE_FLAG) ? " PRIMARY_SOURCE" : "",
flags);
return 1;
@ -2315,8 +2315,8 @@ static int _udev_wait(uint32_t cookie)
return 0;
}
log_debug("Udev cookie 0x%" PRIx32 " (semid %d) waiting for zero",
cookie, semid);
log_debug_activation("Udev cookie 0x%" PRIx32 " (semid %d) waiting for zero",
cookie, semid);
repeat_wait:
if (semop(semid, &sb, 1) < 0) {

View File

@ -541,10 +541,10 @@ void dm_tree_node_set_udev_flags(struct dm_tree_node *dnode, uint16_t udev_flags
struct dm_info *dinfo = &dnode->info;
if (udev_flags != dnode->udev_flags)
log_debug("Resetting %s (%" PRIu32 ":%" PRIu32
") udev_flags from 0x%x to 0x%x",
dnode->name, dinfo->major, dinfo->minor,
dnode->udev_flags, udev_flags);
log_debug_activation("Resetting %s (%" PRIu32 ":%" PRIu32
") udev_flags from 0x%x to 0x%x",
dnode->name, dinfo->major, dinfo->minor,
dnode->udev_flags, udev_flags);
dnode->udev_flags = udev_flags;
}
@ -927,8 +927,8 @@ static int _node_has_closed_parents(struct dm_tree_node *node,
continue;
if (info.open_count) {
log_debug("Node %s %d:%d has open_count %d", uuid_prefix,
dinfo->major, dinfo->minor, info.open_count);
log_debug_activation("Node %s %d:%d has open_count %d", uuid_prefix,
dinfo->major, dinfo->minor, info.open_count);
return 0;
}
}
@ -1263,13 +1263,13 @@ static int _resume_node(const char *name, uint32_t major, uint32_t minor,
log_verbose("Resuming %s (%" PRIu32 ":%" PRIu32 ")", name, major, minor);
if (!(dmt = dm_task_create(DM_DEVICE_RESUME))) {
log_debug("Suspend dm_task creation failed for %s.", name);
log_debug_activation("Suspend dm_task creation failed for %s.", name);
return 0;
}
/* FIXME Kernel should fill in name on return instead */
if (!dm_task_set_name(dmt, name)) {
log_debug("Failed to set device name for %s resumption.", name);
log_debug_activation("Failed to set device name for %s resumption.", name);
goto out;
}
@ -1376,7 +1376,7 @@ static int _thin_pool_status_transaction_id(struct dm_tree_node *dnode, uint64_t
goto out;
}
log_debug("Thin pool transaction id: %" PRIu64 " status: %s.", *transaction_id, params);
log_debug_activation("Thin pool transaction id: %" PRIu64 " status: %s.", *transaction_id, params);
r = 1;
out:
@ -1474,7 +1474,7 @@ static int _node_send_messages(struct dm_tree_node *dnode,
return_0;
if (!_uuid_prefix_matches(uuid, uuid_prefix, uuid_prefix_len)) {
log_debug("UUID \"%s\" does not match.", uuid);
log_debug_activation("UUID \"%s\" does not match.", uuid);
return 1;
}
@ -2321,10 +2321,10 @@ static int _emit_segment_line(struct dm_task *dmt, uint32_t major,
break;
}
log_debug("Adding target to (%" PRIu32 ":%" PRIu32 "): %" PRIu64
" %" PRIu64 " %s %s", major, minor,
*seg_start, seg->size, target_type_is_raid ? "raid" :
dm_segtypes[seg->type].target, params);
log_debug_activation("Adding target to (%" PRIu32 ":%" PRIu32 "): %" PRIu64
" %" PRIu64 " %s %s", major, minor,
*seg_start, seg->size, target_type_is_raid ? "raid" :
dm_segtypes[seg->type].target, params);
if (!dm_task_add_target(dmt, *seg_start, seg->size,
target_type_is_raid ? "raid" :
@ -2362,8 +2362,8 @@ static int _emit_segment(struct dm_task *dmt, uint32_t major, uint32_t minor,
if (ret >= 0)
return ret;
log_debug("Insufficient space in params[%" PRIsize_t
"] for target parameters.", paramsize);
log_debug_activation("Insufficient space in params[%" PRIsize_t
"] for target parameters.", paramsize);
paramsize *= 2;
} while (paramsize < MAX_TARGET_PARAMSIZE);
@ -2428,11 +2428,11 @@ static int _load_node(struct dm_tree_node *dnode)
if (!existing_table_size && dnode->props.delay_resume_if_new)
dnode->props.size_changed = 0;
log_debug("Table size changed from %" PRIu64 " to %"
PRIu64 " for %s (%" PRIu32 ":%" PRIu32 ").%s",
existing_table_size, seg_start, dnode->name,
dnode->info.major, dnode->info.minor,
dnode->props.size_changed ? "" : " (Ignoring.)");
log_debug_activation("Table size changed from %" PRIu64 " to %"
PRIu64 " for %s (%" PRIu32 ":%" PRIu32 ").%s",
existing_table_size, seg_start, dnode->name,
dnode->info.major, dnode->info.minor,
dnode->props.size_changed ? "" : " (Ignoring.)");
}
}
@ -3096,8 +3096,8 @@ int dm_tree_node_add_thin_pool_target(struct dm_tree_node *node,
dm_list_iterate_items(mseg, &seg->metadata->props.segs) {
devsize += mseg->size;
if (devsize > max_metadata_size) {
log_debug("Ignoring %" PRIu64 " of device.",
devsize - max_metadata_size);
log_debug_activation("Ignoring %" PRIu64 " of device.",
devsize - max_metadata_size);
mseg->size -= (devsize - max_metadata_size);
devsize = max_metadata_size;
/* FIXME: drop remaining segs */

View File

@ -117,7 +117,7 @@ void *dm_malloc_aux_debug(size_t s, const char *file, int line)
if (_mem_stats.bytes > _mem_stats.mbytes)
_mem_stats.mbytes = _mem_stats.bytes;
/* log_debug("Allocated: %u %u %u", nb->id, _mem_stats.blocks_allocated,
/* log_debug_mem("Allocated: %u %u %u", nb->id, _mem_stats.blocks_allocated,
_mem_stats.bytes); */
#ifdef VALGRIND_POOL
VALGRIND_MAKE_MEM_UNDEFINED(nb + 1, s);

View File

@ -62,7 +62,7 @@ struct dm_pool *dm_pool_create(const char *name, size_t chunk_hint)
mem->orig_pool = mem;
#ifdef DEBUG_POOL
log_debug("Created mempool %s", name);
log_debug_mem("Created mempool %s", name);
#endif
dm_list_add(&_dm_pools, &mem->list);
@ -91,10 +91,10 @@ static void _free_blocks(struct dm_pool *p, struct block *b)
static void _pool_stats(struct dm_pool *p, const char *action)
{
#ifdef DEBUG_POOL
log_debug("%s mempool %s: %u/%u bytes, %u/%u blocks, "
"%u allocations)", action, p->name, p->stats.bytes,
p->stats.maxbytes, p->stats.blocks_allocated,
p->stats.blocks_max, p->stats.block_serialno);
log_debug_mem("%s mempool %s: %u/%u bytes, %u/%u blocks, "
"%u allocations)", action, p->name, p->stats.bytes,
p->stats.maxbytes, p->stats.blocks_allocated,
p->stats.blocks_max, p->stats.block_serialno);
#else
;
#endif

View File

@ -141,7 +141,7 @@ int dm_pool_lock(struct dm_pool *p, int crc)
p->locked = 1;
log_debug("Pool %s is locked.", p->name);
log_debug_mem("Pool %s is locked.", p->name);
return 1;
}
@ -172,7 +172,7 @@ int dm_pool_unlock(struct dm_pool *p, int crc)
if (!_pool_protect(p, PROT_READ | PROT_WRITE))
return_0;
log_debug("Pool %s is unlocked.", p->name);
log_debug_mem("Pool %s is unlocked.", p->name);
if (crc && (p->crc != _pool_crc(p))) {
log_error(INTERNAL_ERROR "Pool %s crc mismatch.", p->name);

View File

@ -971,6 +971,7 @@ int help(struct cmd_context *cmd __attribute__((unused)), int argc, char **argv)
static void _apply_settings(struct cmd_context *cmd)
{
init_debug(cmd->current_settings.debug);
init_debug_classes_logged(cmd->default_settings.debug_classes);
init_verbose(cmd->current_settings.verbose + VERBOSE_BASE_LEVEL);
init_silent(cmd->current_settings.silent);
init_test(cmd->current_settings.test);

View File

@ -148,7 +148,7 @@ static int _pvscan_lvmetad(struct cmd_context *cmd, int argc, char **argv)
/* TODO: Remove this once lvmetad + cluster supported! */
if (find_config_tree_int(cmd, "global/locking_type", 1) == 3 ||
!find_config_tree_int(cmd, "global/use_lvmetad", 0)) {
log_debug("_pvscan_lvmetad: immediate return");
log_debug_lvmetad("_pvscan_lvmetad: immediate return");
return ret;
}