dmsetup: Report timestamps of ioctls with -vvv.

If enabled, record timestamp immediately after the ioctl() returns.

6 files changed, 45 insertions, 4 deletions

diff --git a/libdm/.exported_symbols.DM_1_02_104 b/libdm/.exported_symbols.DM_1_02_104
index 003941926..ec5c50b5d 100644
--- a/libdm/.exported_symbols.DM_1_02_104
+++ b/libdm/.exported_symbols.DM_1_02_104
@@ -4,6 +4,8 @@ dm_report_set_interval_ms
 dm_report_set_interval_ns
 dm_report_wait
 dm_size_to_string
+dm_task_get_ioctl_timestamp
+dm_task_set_record_timestamp
 dm_timestamp_alloc
 dm_timestamp_compare
 dm_timestamp_delta
diff --git a/libdm/ioctl/libdm-iface.c b/libdm/ioctl/libdm-iface.c
index e3b33b805..73af12b7a 100644
--- a/libdm/ioctl/libdm-iface.c
+++ b/libdm/ioctl/libdm-iface.c
@@ -68,6 +68,7 @@ static unsigned _dm_version = DM_VERSION_MAJOR;
 static unsigned _dm_version_minor = 0;
 static unsigned _dm_version_patchlevel = 0;
 static int _log_suppress = 0;
+static struct dm_timestamp *_dm_ioctl_timestamp = NULL;
 
 /*
  * If the kernel dm driver only supports one major number
@@ -919,6 +920,24 @@ int dm_task_set_event_nr(struct dm_task *dmt, uint32_t event_nr)
 	return 1;
 }
 
+int dm_task_set_record_timestamp(struct dm_task *dmt)
+{
+	if (!_dm_ioctl_timestamp)
+		_dm_ioctl_timestamp = dm_timestamp_alloc();
+
+	if (!_dm_ioctl_timestamp)
+		return_0;
+
+	dmt->record_timestamp = 1;
+
+	return 1;
+}
+
+struct dm_timestamp *dm_task_get_ioctl_timestamp(struct dm_task *dmt)
+{
+	return dmt->record_timestamp ? _dm_ioctl_timestamp : NULL;
+}
+
 struct target *create_target(uint64_t start, uint64_t len, const char *type,
 			     const char *params)
 {
@@ -1716,6 +1735,7 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
 {
 	struct dm_ioctl *dmi;
 	int ioctl_with_uevent;
+	int r;
 
 	dmt->ioctl_errno = 0;
 
@@ -1803,8 +1823,13 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
 			     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) {
+	r = ioctl(_control_fd, command, dmi);
+
+	if (dmt->record_timestamp)
+		if (!dm_timestamp_get(_dm_ioctl_timestamp))
+			stack;
+
+	if (r < 0 && dmt->expected_errno != errno) {
 		dmt->ioctl_errno = errno;
 		if (dmt->ioctl_errno == ENXIO && ((dmt->type == DM_DEVICE_INFO) ||
 						  (dmt->type == DM_DEVICE_MKNODES) ||
@@ -2049,6 +2074,8 @@ repeat_ioctl:
 void dm_lib_release(void)
 {
 	_close_control_fd();
+	dm_timestamp_destroy(_dm_ioctl_timestamp);
+	_dm_ioctl_timestamp = NULL;
 	update_devs();
 }
 
diff --git a/libdm/ioctl/libdm-targets.h b/libdm/ioctl/libdm-targets.h
index 5545459b0..a3c1cb73d 100644
--- a/libdm/ioctl/libdm-targets.h
+++ b/libdm/ioctl/libdm-targets.h
@@ -70,6 +70,8 @@ struct dm_task {
 	int expected_errno;
 	int ioctl_errno;
 
+	int record_timestamp;
+
 	char *uuid;
 	char *mangled_uuid;
 };
diff --git a/libdm/libdevmapper.h b/libdm/libdevmapper.h
index 4a1703e3e..ed9a79e6c 100644
--- a/libdm/libdevmapper.h
+++ b/libdm/libdevmapper.h
@@ -128,6 +128,7 @@ enum {
  */
 
 struct dm_task;
+struct dm_timestamp;
 
 struct dm_task *dm_task_create(int type);
 void dm_task_destroy(struct dm_task *dmt);
@@ -229,6 +230,12 @@ int dm_task_retry_remove(struct dm_task *dmt);
 int dm_task_deferred_remove(struct dm_task *dmt);
 
 /*
+ * Record timestamp immediately after the ioctl returns.
+ */
+int dm_task_set_record_timestamp(struct dm_task *dmt);
+struct dm_timestamp *dm_task_get_ioctl_timestamp(struct dm_task *dmt);
+
+/*
  * Enable checks for common mistakes such as issuing ioctls in an unsafe order.
  */
 int dm_task_enable_checks(struct dm_task *dmt);
@@ -1669,8 +1676,6 @@ dm_percent_t dm_make_percent(uint64_t numerator, uint64_t denominator);
  * timestamp handling
  ********************/
 
-struct dm_timestamp;
-
 /*
  * Create a dm_timestamp object to use with dm_timestamp_get.
  */
diff --git a/libdm/libdm-common.c b/libdm/libdm-common.c
index 0811db098..e1bd44e96 100644
--- a/libdm/libdm-common.c
+++ b/libdm/libdm-common.c
@@ -277,6 +277,7 @@ struct dm_task *dm_task_create(int type)
 	dmt->query_inactive_table = 0;
 	dmt->new_uuid = 0;
 	dmt->secure_data = 0;
+	dmt->record_timestamp = 0;
 
 	return dmt;
 }
diff --git a/libdm/libdm-timestamp.c b/libdm/libdm-timestamp.c
index d2bd7bf61..7690ccb9d 100644
--- a/libdm/libdm-timestamp.c
+++ b/libdm/libdm-timestamp.c
@@ -67,6 +67,8 @@ int dm_timestamp_get(struct dm_timestamp *ts)
 
 	if (clock_gettime(CLOCK_MONOTONIC, &ts->t)) {
 		log_sys_error("clock_gettime", "get_timestamp");
+		ts->t.tv_sec = 0;
+		ts->t.tv_nsec = 0;
 		return 0;
 	}
 
@@ -113,6 +115,8 @@ int dm_timestamp_get(struct dm_timestamp *ts)
 
 	if (gettimeofday(&ts->t, NULL)) {
 		log_sys_error("gettimeofday", "get_timestamp");
+		ts->t.tv_sec = 0;
+		ts->t.tv_usec = 0;
 		return 0;
 	}