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

log: Improve various device-related messages

Browse Source 
- Use 'lvmcache' consistently instead of 'metadata cache'
- Always use 5 characters for source line number
- Remember to convert uuids into printable form
- Use <no name> rather than (null) when VG has no name.
This commit is contained in:
Alasdair G Kergon 2017-11-13 14:43:32 +00:00
parent 598fcccf45
commit 6bf0f04ae2
11 changed files with 42 additions and 39 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

10
lib/cache/lvmcache.c vendored
View File

@ -154,7 +154,7 @@ static void _free_cached_vgmetadata(struct lvmcache_vginfo *vginfo)
vginfo->cft = NULL; vginfo->cft = NULL;
} }
log_debug_cache("Metadata cache: VG %s wiped.", vginfo->vgname); log_debug_cache("lvmcache: VG %s wiped.", vginfo->vgname);
release_vg(vginfo->cached_vg); release_vg(vginfo->cached_vg);
} }
@ -197,7 +197,7 @@ static void _store_metadata(struct volume_group *vg, unsigned precommitted)
return; return;
} }
log_debug_cache("Metadata cache: VG %s (%s) stored (%" PRIsize_t " bytes%s).", log_debug_cache("lvmcache: VG %s (%s) stored (%" PRIsize_t " bytes%s).",
vginfo->vgname, uuid, size, vginfo->vgname, uuid, size,
precommitted ? ", precommitted" : ""); precommitted ? ", precommitted" : "");
} }
@ -289,7 +289,7 @@ void lvmcache_commit_metadata(const char *vgname)
return; return;
if (vginfo->precommitted) { if (vginfo->precommitted) {
log_debug_cache("Precommitted metadata cache: VG %s upgraded to committed.", log_debug_cache("lvmcache: Upgraded pre-committed VG %s metadata to committed.",
vginfo->vgname); vginfo->vgname);
vginfo->precommitted = 0; vginfo->precommitted = 0;
} }
@ -616,7 +616,7 @@ struct lvmcache_vginfo *lvmcache_vginfo_from_vgid(const char *vgid)
id[ID_LEN] = '\0'; id[ID_LEN] = '\0';
if (!(vginfo = dm_hash_lookup(_vgid_hash, id))) { if (!(vginfo = dm_hash_lookup(_vgid_hash, id))) {
log_debug_cache("Metadata cache has no info for vgid \"%s\"", id); log_debug_cache("lvmcache has no info for vgid \"%s\"", id);
return NULL; return NULL;
} }
@ -1870,7 +1870,7 @@ static int _lvmcache_update_vgname(struct lvmcache_info *info,
vginfo->vgid[0] ? vginfo->vgid : "", vginfo->vgid[0] ? vginfo->vgid : "",
vginfo->vgid[0] ? ")" : "", mdabuf); vginfo->vgid[0] ? ")" : "", mdabuf);
} else } else
log_debug_cache("lvmcache initialised VG %s.", vgname); log_debug_cache("lvmcache: Initialised VG %s.", vgname);
return 1; return 1;
} }

6
lib/device/dev-cache.c
View File

@ -708,7 +708,7 @@ static int _insert_dev(const char *path, dev_t d)
if (dm_hash_lookup(_cache.names, path) == dev) { if (dm_hash_lookup(_cache.names, path) == dev) {
/* Hash already has matching entry present */ /* Hash already has matching entry present */
log_debug("Path already cached %s.", path); log_debug("%s: Path already cached.", path);
return 1; return 1;
} }
@ -1423,7 +1423,7 @@ struct device *dev_cache_get(const char *name, struct dev_filter *f)
if (!d || (f && !(d->flags & DEV_REGULAR) && !(f->passes_filter(f, d)))) if (!d || (f && !(d->flags & DEV_REGULAR) && !(f->passes_filter(f, d))))
return NULL; return NULL;
log_debug_devs("Using %s", dev_name(d)); log_debug_devs("%s: Using device (%d:%d)", dev_name(d), (int) MAJOR(d->dev), (int) MINOR(d->dev));
return d; return d;
} }
@ -1533,7 +1533,7 @@ struct device *dev_iter_get(struct dev_iter *iter)
struct device *d = _iter_next(iter); struct device *d = _iter_next(iter);
if (!iter->filter || (d->flags & DEV_REGULAR) || if (!iter->filter || (d->flags & DEV_REGULAR) ||
iter->filter->passes_filter(iter->filter, d)) { iter->filter->passes_filter(iter->filter, d)) {
log_debug_devs("Using %s", dev_name(d)); log_debug_devs("%s: Using device (%d:%d)", dev_name(d), (int) MAJOR(d->dev), (int) MINOR(d->dev));
return d; return d;
} }
} }

14
lib/device/dev-ext.c
View File

@ -100,8 +100,6 @@ const char *dev_ext_name(struct device *dev)
return _ext_registry[dev->ext.src].name; return _ext_registry[dev->ext.src].name;
} }
static const char *_ext_attached_msg = "External handle attached to device";
struct dev_ext *dev_ext_get(struct device *dev) struct dev_ext *dev_ext_get(struct device *dev)
{ {
struct dev_ext *ext; struct dev_ext *ext;
@ -110,10 +108,10 @@ struct dev_ext *dev_ext_get(struct device *dev)
handle_ptr = dev->ext.handle; handle_ptr = dev->ext.handle;
if (!(ext = _ext_registry[dev->ext.src].dev_ext_get(dev))) if (!(ext = _ext_registry[dev->ext.src].dev_ext_get(dev)))
log_error("Failed to get external handle for device %s [%s].", log_error("%s: Failed to get external handle [%s].",
dev_name(dev), dev_ext_name(dev)); dev_name(dev), dev_ext_name(dev));
else if (handle_ptr != dev->ext.handle) else if (handle_ptr != dev->ext.handle)
log_debug_devs("%s %s [%s:%p]", _ext_attached_msg, dev_name(dev), log_debug_devs("%s: External handle [%s:%p] attached", dev_name(dev),
dev_ext_name(dev), dev->ext.handle); dev_ext_name(dev), dev->ext.handle);
return ext; return ext;
@ -131,10 +129,10 @@ int dev_ext_release(struct device *dev)
handle_ptr = dev->ext.handle; handle_ptr = dev->ext.handle;
if (!(r = _ext_registry[dev->ext.src].dev_ext_release(dev))) if (!(r = _ext_registry[dev->ext.src].dev_ext_release(dev)))
log_error("Failed to release external handle for device %s [%s:%p].", log_error("%s: Failed to release external handle [%s:%p]",
dev_name(dev), dev_ext_name(dev), dev->ext.handle); dev_name(dev), dev_ext_name(dev), dev->ext.handle);
else else
log_debug_devs("External handle detached from device %s [%s:%p]", log_debug_devs("%s: External handle [%s:%p] detached",
dev_name(dev), dev_ext_name(dev), handle_ptr); dev_name(dev), dev_ext_name(dev), handle_ptr);
return r; return r;
@ -143,7 +141,7 @@ int dev_ext_release(struct device *dev)
int dev_ext_enable(struct device *dev, dev_ext_t src) int dev_ext_enable(struct device *dev, dev_ext_t src)
{ {
if (dev->ext.enabled && (dev->ext.src != src) && !dev_ext_release(dev)) { if (dev->ext.enabled && (dev->ext.src != src) && !dev_ext_release(dev)) {
log_error("Failed to enable external handle for device %s [%s].", log_error("%s: Failed to enable external handle [%s].",
dev_name(dev), _ext_registry[src].name); dev_name(dev), _ext_registry[src].name);
return 0; return 0;
} }
@ -160,7 +158,7 @@ int dev_ext_disable(struct device *dev)
return 1; return 1;
if (!dev_ext_release(dev)) { if (!dev_ext_release(dev)) {
log_error("Failed to disable external handle for device %s [%s].", log_error("%s: Failed to disable external handle [%s].",
dev_name(dev), dev_ext_name(dev)); dev_name(dev), dev_ext_name(dev));
return 0; return 0;
} }

12
lib/device/dev-io.c
View File

@ -142,7 +142,7 @@ int dev_get_block_size(struct device *dev, unsigned int *physical_block_size, un
r = 0; r = 0;
goto out; goto out;
} }
log_debug_devs("%s: block size is %u bytes", name, dev->block_size); log_debug_devs("%s: Block size is %u bytes", name, dev->block_size);
} }
#ifdef BLKPBSZGET #ifdef BLKPBSZGET
@ -153,7 +153,7 @@ int dev_get_block_size(struct device *dev, unsigned int *physical_block_size, un
r = 0; r = 0;
goto out; goto out;
} }
log_debug_devs("%s: physical block size is %u bytes", name, dev->phys_block_size); log_debug_devs("%s: Physical block size is %u bytes", name, dev->phys_block_size);
} }
#elif defined (BLKSSZGET) #elif defined (BLKSSZGET)
/* if we can't get physical block size, just use logical block size instead */ /* if we can't get physical block size, just use logical block size instead */
@ -163,15 +163,13 @@ int dev_get_block_size(struct device *dev, unsigned int *physical_block_size, un
r = 0; r = 0;
goto out; goto out;
} }
log_debug_devs("%s: physical block size can't be determined, using logical " log_debug_devs("%s: Physical block size can't be determined: Using logical block size of %u bytes", name, dev->phys_block_size);
"block size of %u bytes", name, dev->phys_block_size);
} }
#else #else
/* if even BLKSSZGET is not available, use default 512b */ /* if even BLKSSZGET is not available, use default 512b */
if (dev->phys_block_size == -1) { if (dev->phys_block_size == -1) {
dev->phys_block_size = 512; dev->phys_block_size = 512;
log_debug_devs("%s: physical block size can't be determined, using block " log_debug_devs("%s: Physical block size can't be determined: Using block size of %u bytes instead", name, dev->phys_block_size);
"size of %u bytes instead", name, dev->phys_block_size);
} }
#endif #endif
@ -464,7 +462,7 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
} }
if (dev->open_count && !need_excl) { if (dev->open_count && !need_excl) {
log_debug_devs("%s already opened read-only. Upgrading " log_debug_devs("%s: Already opened read-only. Upgrading "
"to read-write.", dev_name(dev)); "to read-write.", dev_name(dev));
dev->open_count++; dev->open_count++;
} }

2
lib/filters/filter-internal.c
View File

@ -74,7 +74,7 @@ struct dev_filter *internal_filter_create(void)
f->destroy = _destroy; f->destroy = _destroy;
f->use_count = 0; f->use_count = 0;
log_debug_devs("internal filter initialised."); log_debug_devs("Internal filter initialised.");
return f; return f;
} }

1
lib/filters/filter-persistent.c
View File

@ -119,6 +119,7 @@ int persistent_filter_load(struct dev_filter *f, struct dm_config_tree **cft_out
if (!config_file_read(cft)) if (!config_file_read(cft))
goto_out; goto_out;
log_debug_devs("Loading persistent filter cache from %s", pf->file);
_read_array(pf, cft, "persistent_filter_cache/valid_devices", _read_array(pf, cft, "persistent_filter_cache/valid_devices",
PF_GOOD_DEVICE); PF_GOOD_DEVICE);
/* We don't gain anything by holding invalid devices */ /* We don't gain anything by holding invalid devices */

8
lib/log/log.c
View File

@ -594,7 +594,7 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c
log_it: log_it:
if (!logged_via_report && ((verbose_level() >= level) && !_log_suppress)) { if (!logged_via_report && ((verbose_level() >= level) && !_log_suppress)) {
if (verbose_level() > _LOG_DEBUG) { if (verbose_level() > _LOG_DEBUG) {
(void) dm_snprintf(buf, sizeof(buf), "#%s:%d ", (void) dm_snprintf(buf, sizeof(buf), "#%s:%-5d ",
file, line); file, line);
} else } else
buf[0] = '\0'; buf[0] = '\0';
@ -639,7 +639,7 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c
} }
if (_log_to_file && (_log_while_suspended || !critical_section())) { if (_log_to_file && (_log_while_suspended || !critical_section())) {
fprintf(_log_file, "%s:%d %s%s", file, line, log_command_name(), fprintf(_log_file, "%s:%-5d %s%s", file, line, log_command_name(),
_msg_prefix); _msg_prefix);
va_copy(ap, orig_ap); va_copy(ap, orig_ap);
@ -647,7 +647,7 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c
va_end(ap); va_end(ap);
if (_log_file_max_lines && ++_log_file_lines >= _log_file_max_lines) { if (_log_file_max_lines && ++_log_file_lines >= _log_file_max_lines) {
fprintf(_log_file, "\n%s:%d %sAborting. Command has reached limit " fprintf(_log_file, "\n%s:%-5d %sAborting. Command has reached limit "
"for logged lines (LVM_LOG_FILE_MAX_LINES=" FMTu64 ").", "for logged lines (LVM_LOG_FILE_MAX_LINES=" FMTu64 ").",
file, line, _msg_prefix, file, line, _msg_prefix,
_log_file_max_lines); _log_file_max_lines);
@ -673,7 +673,7 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c
memset(&buf, ' ', sizeof(buf)); memset(&buf, ' ', sizeof(buf));
bufused = 0; bufused = 0;
if ((n = dm_snprintf(buf, sizeof(buf), if ((n = dm_snprintf(buf, sizeof(buf),
"%s:%d %s%s", file, line, log_command_name(), "%s:%-5d %s%s", file, line, log_command_name(),
_msg_prefix)) == -1) _msg_prefix)) == -1)
goto done; goto done;

10
lib/metadata/metadata.c
View File

@ -3797,12 +3797,18 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
struct dm_list *pvids; struct dm_list *pvids;
struct pv_list *pvl; struct pv_list *pvl;
struct dm_list all_pvs; struct dm_list all_pvs;
char uuid[64] __attribute__((aligned(8)));
unsigned seqno = 0; unsigned seqno = 0;
int reappeared = 0; int reappeared = 0;
struct cached_vg_fmtdata *vg_fmtdata = NULL; /* Additional format-specific data about the vg */ struct cached_vg_fmtdata *vg_fmtdata = NULL; /* Additional format-specific data about the vg */
unsigned use_previous_vg; unsigned use_previous_vg;
log_very_verbose("Reading VG %s %.32s", vgname ?: "<no name>", vgid ?: "<no vgid>"); uuid[0] = '\0';
if (vgid && !id_write_format((const struct id*)vgid, uuid, sizeof(uuid)))
stack;
log_very_verbose("Reading VG %s %s", vgname ?: "<no name>", vgid ? uuid : "<no vgid>");
if (is_orphan_vg(vgname)) { if (is_orphan_vg(vgname)) {
if (use_precommitted) { if (use_precommitted) {
@ -3879,7 +3885,7 @@ static struct volume_group *_vg_read(struct cmd_context *cmd,
/* Now determine the correct vgname if none was supplied */ /* Now determine the correct vgname if none was supplied */
if (!vgname && !(vgname = lvmcache_vgname_from_vgid(cmd->mem, vgid))) { if (!vgname && !(vgname = lvmcache_vgname_from_vgid(cmd->mem, vgid))) {
log_debug_metadata("Cache did not find VG name from vgid %.32s", vgid); log_debug_metadata("Cache did not find VG name from vgid %s", uuid);
return_NULL; return_NULL;
} }

4
lib/metadata/vg.c
View File

@ -71,7 +71,7 @@ struct volume_group *alloc_vg(const char *pool_name, struct cmd_context *cmd,
dm_list_init(&vg->removed_historical_lvs); dm_list_init(&vg->removed_historical_lvs);
dm_list_init(&vg->removed_pvs); dm_list_init(&vg->removed_pvs);
log_debug_mem("Allocated VG %s at %p.", vg->name, vg); log_debug_mem("Allocated VG %s at %p.", vg->name ? : "<no name>", vg);
return vg; return vg;
} }
@ -86,7 +86,7 @@ static void _free_vg(struct volume_group *vg)
return; return;
} }
log_debug_mem("Freeing VG %s at %p.", vg->name, vg); log_debug_mem("Freeing VG %s at %p.", vg->name ? : "<no name>", vg);
dm_hash_destroy(vg->hostnames); dm_hash_destroy(vg->hostnames);
dm_pool_destroy(vg->vgmem); dm_pool_destroy(vg->vgmem);

8
tools/lvmcmdline.c
View File

@ -1864,8 +1864,8 @@ out:
} }
} }
log_debug("Using command index %d id %s enum %d.", log_debug("Recognised command %s (id %d / enum %d).",
best_i, commands[best_i].command_id, commands[best_i].command_enum); commands[best_i].command_id, best_i, commands[best_i].command_enum);
return &commands[best_i]; return &commands[best_i];
} }
@ -2873,9 +2873,9 @@ int lvm_run_command(struct cmd_context *cmd, int argc, char **argv)
goto_out; goto_out;
init_dmeventd_monitor(monitoring); init_dmeventd_monitor(monitoring);
log_debug("Processing: %s", cmd->cmd_line); log_debug("Processing command: %s", cmd->cmd_line);
log_debug("Command pid: %d", getpid()); log_debug("Command pid: %d", getpid());
log_debug("system ID: %s", cmd->system_id ? : ""); log_debug("System ID: %s", cmd->system_id ? : "");
#ifdef O_DIRECT_SUPPORT #ifdef O_DIRECT_SUPPORT
log_debug("O_DIRECT will be used"); log_debug("O_DIRECT will be used");

6
tools/toollib.c
View File

@ -1967,7 +1967,7 @@ static int _process_vgnameid_list(struct cmd_context *cmd, uint32_t read_flags,
(!dm_list_empty(arg_tags) && str_list_match_list(arg_tags, &vg->tags, NULL))) && (!dm_list_empty(arg_tags) && str_list_match_list(arg_tags, &vg->tags, NULL))) &&
select_match_vg(cmd, handle, vg) && _select_matches(handle)) { select_match_vg(cmd, handle, vg) && _select_matches(handle)) {
log_very_verbose("Process single VG %s", vg_name); log_very_verbose("Processing VG %s %s", vg_name, vg_uuid ? uuid : "");
ret = process_single_vg(cmd, vg_name, vg, handle); ret = process_single_vg(cmd, vg_name, vg, handle);
_update_selection_result(handle, &whole_selected); _update_selection_result(handle, &whole_selected);
@ -2231,7 +2231,7 @@ int process_each_vg(struct cmd_context *cmd,
* . A VG name is specified which may refer to one * . A VG name is specified which may refer to one
* of multiple VGs on the system with that name. * of multiple VGs on the system with that name.
*/ */
log_debug("Get list of VGs on system"); log_very_verbose("Obtaining the complete list of VGs to process");
if (!get_vgnameids(cmd, &vgnameids_on_system, NULL, include_internal)) { if (!get_vgnameids(cmd, &vgnameids_on_system, NULL, include_internal)) {
ret_max = ECMD_FAILED; ret_max = ECMD_FAILED;
@ -3733,7 +3733,7 @@ int process_each_lv(struct cmd_context *cmd,
* . A VG name is specified which may refer to one * . A VG name is specified which may refer to one
* of multiple VGs on the system with that name. * of multiple VGs on the system with that name.
*/ */
log_debug("Get list of VGs on system"); log_very_verbose("Obtaining the complete list of VGs before processing their LVs");
if (!get_vgnameids(cmd, &vgnameids_on_system, NULL, 0)) { if (!get_vgnameids(cmd, &vgnameids_on_system, NULL, 0)) {
ret_max = ECMD_FAILED; ret_max = ECMD_FAILED;