Additional device-handling debug messages.

Additional verbosity level -vvvv includes line numbers and backtraces.
Verbose messages now go to stderr not stdout.
Close any stray file descriptors before starting.
Refine partitionable checks for certain device types.
Allow devices/types to override built-ins.

WHATS_NEW

@@ -1,5 +1,11 @@
 Version 2.00.30 - 
 ====================================
+  Additional device-handling debug messages.
+  Additional verbosity level -vvvv includes line numbers and backtraces.
+  Verbose messages now go to stderr not stdout.
+  Close any stray file descriptors before starting.
+  Refine partitionable checks for certain device types.
+  Allow devices/types to override built-ins.
   Fix lvreduce man page .i->.I
   Fix vgsplit man page title.
   Fix clvmd man makefile.

lib/commands/toolcontext.c

@@ -519,8 +519,8 @@ static struct dev_filter *_init_filter_components(struct cmd_context *cmd)
 
 	/* regex filter. Optional. */
 	if (!(cn = find_config_node(cmd->cft->root, "devices/filter")))
-		log_debug("devices/filter not found in config file: no regex "
+		log_very_verbose("devices/filter not found in config file: "
-			  "filter installed");
+				 "no regex filter installed");
 
 	else if (!(filters[nr_filt++] = regex_filter_create(cn->v))) {
 		log_error("Failed to create regex device filter");

lib/device/dev-cache.c

@@ -82,6 +82,7 @@ struct device *dev_create_file(const char *filename, struct device *dev,
 	dev->dev = 0;
 	dev->fd = -1;
 	dev->open_count = 0;
+	dev->block_size = -1;
 	memset(dev->pvid, 0, sizeof(dev->pvid));
 	list_init(&dev->open_list);
 
@@ -101,6 +102,7 @@ static struct device *_dev_create(dev_t d)
 	dev->dev = d;
 	dev->fd = -1;
 	dev->open_count = 0;
+	dev->block_size = -1;
 	dev->end = UINT64_C(0);
 	memset(dev->pvid, 0, sizeof(dev->pvid));
 	list_init(&dev->open_list);

lib/device/dev-io.c

@@ -81,7 +81,9 @@ static int _io(struct device_area *where, void *buffer, int should_write)
 	}
 
 	if (lseek(fd, (off_t) where->start, SEEK_SET) < 0) {
-		log_sys_error("lseek", dev_name(where->dev));
+		log_error("%s: lseek %" PRIu64 " failed: %s",
+			  dev_name(where->dev), (uint64_t) where->start,
+			  strerror(errno));
 		return 0;
 	}
 
@@ -92,6 +94,14 @@ static int _io(struct device_area *where, void *buffer, int should_write)
 			    read(fd, buffer, (size_t) where->size - total);
 		while ((n < 0) && ((errno == EINTR) || (errno == EAGAIN)));
 
+		if (n < 0)
+			log_error("%s: %s failed after %" PRIu64 " of %" PRIu64
+				  " at %" PRIu64 ": %s", dev_name(where->dev),
+				  should_write ? "write" : "read",
+				  (uint64_t) total,
+				  (uint64_t) where->size,
+				  (uint64_t) where->start, strerror(errno));
+
 		if (n <= 0)
 			break;
 
@@ -114,14 +124,18 @@ static int _io(struct device_area *where, void *buffer, int should_write)
  */
 static int _get_block_size(struct device *dev, unsigned int *size)
 {
-	int s;
+	const char *name = dev_name(dev);
 
-	if (ioctl(dev_fd(dev), BLKBSZGET, &s) < 0) {
+	if ((dev->block_size == -1)) {
-		log_sys_error("ioctl BLKBSZGET", dev_name(dev));
+		if (ioctl(dev_fd(dev), BLKBSZGET, &dev->block_size) < 0) {
-		return 0;
+			log_sys_error("ioctl BLKBSZGET", name);
+			return 0;
+		}
+		log_debug("%s: block size is %u bytes", name, dev->block_size);
 	}
 
-	*size = (unsigned int) s;
+	*size = (unsigned int) dev->block_size;
+
 	return 1;
 }
 
@@ -217,7 +231,6 @@ int dev_get_size(const struct device *dev, uint64_t *size)
 	int fd;
 	const char *name = dev_name(dev);
 
-	log_very_verbose("Getting size of %s", name);
 	if ((fd = open(name, O_RDONLY)) < 0) {
 		log_sys_error("open", name);
 		return 0;
@@ -231,16 +244,19 @@ int dev_get_size(const struct device *dev, uint64_t *size)
 
 	*size >>= BLKSIZE_SHIFT;	/* Convert to sectors */
 	close(fd);
+
+	log_very_verbose("%s: size is %" PRIu64 " sectors", name, *size);
+
 	return 1;
 }
 
+/* FIXME Unused
 int dev_get_sectsize(struct device *dev, uint32_t *size)
 {
 	int fd;
 	int s;
 	const char *name = dev_name(dev);
 
-	log_very_verbose("Getting size of %s", name);
 	if ((fd = open(name, O_RDONLY)) < 0) {
 		log_sys_error("open", name);
 		return 0;
@@ -254,8 +270,12 @@ int dev_get_sectsize(struct device *dev, uint32_t *size)
 
 	close(fd);
 	*size = (uint32_t) s;
+
+	log_very_verbose("%s: sector size is %" PRIu32 " bytes", name, *size);
+
 	return 1;
 }
+*/
 
 void dev_flush(struct device *dev)
 {
@@ -274,6 +294,10 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
 	const char *name;
 
 	if (dev->fd >= 0) {
+		if (!(dev->flags & DEV_OPENED_RW) &&
+		    ((flags & O_ACCMODE) == O_RDWR))
+			log_debug("WARNING: %s already opened read-only",
+				  dev_name(dev));
 		dev->open_count++;
 		return 1;
 	}
@@ -313,6 +337,10 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
 
 	dev->open_count = 1;
 	dev->flags &= ~DEV_ACCESSED_W;
+	if ((flags & O_ACCMODE) == O_RDWR)
+		dev->flags |= DEV_OPENED_RW;
+	else
+		dev->flags &= ~DEV_OPENED_RW;
 
 	if (!(dev->flags & DEV_REGULAR) &&
 	    ((fstat(dev->fd, &buf) < 0) || (buf.st_rdev != dev->dev))) {
@@ -327,13 +355,13 @@ int dev_open_flags(struct device *dev, int flags, int direct, int quiet)
 		dev_flush(dev);
 #endif
 
-	if ((flags & O_CREAT) && !(flags & O_TRUNC)) {
+	if ((flags & O_CREAT) && !(flags & O_TRUNC))
 		dev->end = lseek(dev->fd, (off_t) 0, SEEK_END);
-	}
 
 	list_add(&_open_devices, &dev->open_list);
+
 	log_debug("Opened %s %s", dev_name(dev),
-		  flags & O_RDONLY ? "RO" : "RW");
+		  dev->flags & DEV_OPENED_RW ? "RW" : "RO");
 
 	return 1;
 }
@@ -361,6 +389,7 @@ static void _close(struct device *dev)
 	if (close(dev->fd))
 		log_sys_error("close", dev_name(dev));
 	dev->fd = -1;
+	dev->block_size = -1;
 	list_del(&dev->open_list);
 
 	log_debug("Closed %s", dev_name(dev));
@@ -502,6 +531,5 @@ int dev_zero(struct device *dev, uint64_t offset, size_t len)
 	if (!dev_close(dev))
 		stack;
 
-	/* FIXME: Always display error */
 	return (len == 0);
 }

lib/device/device.c

@@ -27,7 +27,7 @@ static int _is_partitionable(struct device *dev)
 {
 	int parts = max_partitions(MAJOR(dev->dev));
 
-	if (!parts || (MINOR(dev->dev) % parts))
+	if ((parts <= 1) || (MINOR(dev->dev) % parts))
 		return 0;
 
 	return 1;

lib/device/device.h

@@ -22,6 +22,7 @@
 #define DEV_ACCESSED_W		0x00000001	/* Device written to? */
 #define DEV_REGULAR		0x00000002	/* Regular file? */
 #define DEV_ALLOCED		0x00000004	/* dbg_malloc used */
+#define DEV_OPENED_RW		0x00000008	/* Opened RW */
 
 /*
  * All devices in LVM will be represented by one of these.
@@ -34,6 +35,7 @@ struct device {
 	/* private */
 	int fd;
 	int open_count;
+	int block_size;
 	uint32_t flags;
 	uint64_t end;
 	struct list open_list;

lib/filters/filter.c

@@ -28,6 +28,7 @@
 #define NUMBER_OF_MAJORS 4096
 
 /* FIXME Make this sparse */
+/* 0 means LVM won't use this major number. */
 static int _max_partitions_by_major[NUMBER_OF_MAJORS];
 
 typedef struct {
@@ -42,12 +43,19 @@ int md_major(void)
 	return _md_major;
 }
 
-/* This list can be supplemented with devices/types in the config file */
+/*
+ * Devices are only checked for partition tables if their minor number
+ * is a multiple of the number corresponding to their type below
+ * i.e. this gives the granularity of whole-device minor numbers.
+ * Use 1 if the device is not partitionable.
+ *
+ * The list can be supplemented with devices/types in the config file.
+ */
 static const device_info_t device_info[] = {
-	{"ide", 16},		/* IDE disk */
+	{"ide", 64},		/* IDE disk */
 	{"sd", 16},		/* SCSI disk */
-	{"md", 16},		/* Multiple Disk driver (SoftRAID) */
+	{"md", 1},		/* Multiple Disk driver (SoftRAID) */
-	{"loop", 16},		/* Loop device */
+	{"loop", 1},		/* Loop device */
 	{"dasd", 4},		/* DASD disk (IBM S/390, zSeries) */
 	{"dac960", 8},		/* DAC960 */
 	{"nbd", 16},		/* Network Block Device */
@@ -56,6 +64,7 @@ static const device_info_t device_info[] = {
 	{"ubd", 16},		/* User-mode virtual block device */
 	{"ataraid", 16},	/* ATA Raid */
 	{"drbd", 16},		/* Distributed Replicated Block Device */
+	{"emcpower", 16},	/* EMC Powerpath */
 	{"power2", 16},		/* EMC Powerpath */
 	{"i2o_block", 16},	/* i2o Block Disk */
 	{"iseries/vd", 8},	/* iSeries disks */
@@ -104,6 +113,7 @@ static int _scan_proc_dev(const char *proc, const struct config_node *cn)
 	struct config_value *cv;
 	char *name;
 
+
 	if (!*proc) {
 		log_verbose("No proc filesystem found: using all block device "
 			    "types");
@@ -112,6 +122,7 @@ static int _scan_proc_dev(const char *proc, const struct config_node *cn)
 		return 1;
 	}
 
+	/* All types unrecognised initially */
 	memset(_max_partitions_by_major, 0, sizeof(int) * NUMBER_OF_MAJORS);
 
 	if (lvm_snprintf(proc_devices, sizeof(proc_devices),
@@ -165,7 +176,7 @@ static int _scan_proc_dev(const char *proc, const struct config_node *cn)
 			}
 		}
 
-		if (_max_partitions_by_major[line_maj] || !cn)
+		if (!cn)
 			continue;
 
 		/* Check devices/types for local variations */

lib/log/log.c

@@ -226,7 +226,7 @@ int debug_level()
 void print_log(int level, const char *file, int line, const char *format, ...)
 {
 	va_list ap;
-	char buf[1024], buf2[4096];
+	char buf[1024], buf2[4096], locn[4096];
 	int bufused, n;
 	const char *message;
 	const char *trformat;		/* Translated format string */
@@ -254,36 +254,46 @@ void print_log(int level, const char *file, int line, const char *format, ...)
 
       log_it:
 	if (!_log_suppress) {
+		if (_verbose_level > _LOG_DEBUG)
+			lvm_snprintf(locn, sizeof(locn), "#%s:%d ",
+				     file, line);
+		else
+			locn[0] = '\0';
+
 		va_start(ap, format);
 		switch (level) {
 		case _LOG_DEBUG:
-			if (!strcmp("<backtrace>", format))
+			if (!strcmp("<backtrace>", format) &&
+			    _verbose_level <= _LOG_DEBUG)
 				break;
 			if (_verbose_level >= _LOG_DEBUG) {
-				printf("%s%s", _cmd_name, _msg_prefix);
+				fprintf(stderr, "%s%s%s", locn, _cmd_name,
+					_msg_prefix);
 				if (_indent)
-					printf("      ");
+					fprintf(stderr, "      ");
-				vprintf(trformat, ap);
+				vfprintf(stderr, trformat, ap);
-				putchar('\n');
+				fputc('\n', stderr);
 			}
 			break;
 
 		case _LOG_INFO:
 			if (_verbose_level >= _LOG_INFO) {
-				printf("%s%s", _cmd_name, _msg_prefix);
+				fprintf(stderr, "%s%s%s", locn, _cmd_name,
+					_msg_prefix);
 				if (_indent)
-					printf("    ");
+					fprintf(stderr, "    ");
-				vprintf(trformat, ap);
+				vfprintf(stderr, trformat, ap);
-				putchar('\n');
+				fputc('\n', stderr);
 			}
 			break;
 		case _LOG_NOTICE:
 			if (_verbose_level >= _LOG_NOTICE) {
-				printf("%s%s", _cmd_name, _msg_prefix);
+				fprintf(stderr, "%s%s%s", locn, _cmd_name,
+					_msg_prefix);
 				if (_indent)
-					printf("  ");
+					fprintf(stderr, "  ");
-				vprintf(trformat, ap);
+				vfprintf(stderr, trformat, ap);
-				putchar('\n');
+				fputc('\n', stderr);
 			}
 			break;
 		case _LOG_WARN:
@@ -295,7 +305,8 @@ void print_log(int level, const char *file, int line, const char *format, ...)
 			break;
 		case _LOG_ERR:
 			if (_verbose_level >= _LOG_ERR) {
-				fprintf(stderr, "%s%s", _cmd_name, _msg_prefix);
+				fprintf(stderr, "%s%s%s", locn, _cmd_name,
+					_msg_prefix);
 				vfprintf(stderr, trformat, ap);
 				fputc('\n', stderr);
 			}
@@ -303,7 +314,8 @@ void print_log(int level, const char *file, int line, const char *format, ...)
 		case _LOG_FATAL:
 		default:
 			if (_verbose_level >= _LOG_FATAL) {
-				fprintf(stderr, "%s%s", _cmd_name, _msg_prefix);
+				fprintf(stderr, "%s%s%s", locn, _cmd_name,
+					_msg_prefix);
 				vfprintf(stderr, trformat, ap);
 				fputc('\n', stderr);
 			}

tools/lvmcmdline.c

@@ -26,6 +26,7 @@
 #include <libgen.h>
 #include <sys/stat.h>
 #include <time.h>
+#include <sys/resource.h>
 
 #ifdef HAVE_GETOPTLONG
 #  include <getopt.h>
@@ -807,7 +808,7 @@ static int _run_command(struct cmd_context *cmd, int argc, char **argv)
 	if (!(cmd->cmd_line = _copy_command_line(cmd, argc, argv)))
 		return ECMD_FAILED;
 
-	log_debug("Processing: %s", cmd->cmd_line);
+	log_debug("Parsing: %s", cmd->cmd_line);
 
 	if (!(cmd->command = _find_command(argv[0])))
 		return ENO_SUCH_CMD;
@@ -831,6 +832,12 @@ static int _run_command(struct cmd_context *cmd, int argc, char **argv)
 		goto out;
 	_apply_settings(cmd);
 
+	log_debug("Processing: %s", cmd->cmd_line);
+
+#ifdef O_DIRECT_SUPPORT
+	log_debug("O_DIRECT will be used");
+#endif
+
 	if ((ret = _process_common_commands(cmd)))
 		goto out;
 
@@ -967,10 +974,32 @@ static int _init_backup(struct cmd_context *cmd, struct config_tree *cft)
 	return 1;
 }
 
+static void _close_stray_fds(void)
+{
+	struct rlimit rlim;
+	int fd;
+
+	if (getrlimit(RLIMIT_NOFILE, &rlim) < 0) {
+		fprintf(stderr, "getrlimit(RLIMIT_NOFILE) failed: %s\n",
+			strerror(errno));
+		return;
+	}
+
+	for (fd = 3; fd < rlim.rlim_cur; fd++) {
+		if (!close(fd))
+			fprintf(stderr, "File descriptor %d left open\n", fd);
+		else if (errno != EBADF)
+			fprintf(stderr, "Close failed on stray file ",
+				"descriptor %d: %s\n", fd, strerror(errno));
+	}
+}
+
 static struct cmd_context *_init_lvm(void)
 {
 	struct cmd_context *cmd;
 
+	_close_stray_fds();
+
 	if (!(cmd = create_toolcontext(&the_args[0]))) {
 		stack;
 		return NULL;