[PATCH v2 0/2] KVM: selftests: steal_time cleanups and timespec rework

[PATCH v2 0/2] KVM: selftests: steal_time cleanups and timespec rework

[Andrew Jones]

The first patch is a couple changes to steal_time that came to mind
after posting. The second one reworks the timespec functions and
their use. It then applies them to the fixing of the stop condition
of steal_time:do_steal_time

v2:
 - Drank a cup of coffee and discovered division... Use division instead
   of loop in timespec_add_ns.

Andrew Jones (2):
  fixup! KVM: selftests: Introduce steal-time test
  KVM: selftests: Rework timespec functions and usage

 .../selftests/kvm/demand_paging_test.c        | 37 ++++++++----------
 .../testing/selftests/kvm/include/test_util.h |  3 +-
 tools/testing/selftests/kvm/lib/test_util.c   | 37 ++++++++----------
 tools/testing/selftests/kvm/steal_time.c      | 39 +++++++++----------
 4 files changed, 52 insertions(+), 64 deletions(-)

-- 
2.21.1

[PATCH v2 1/2] fixup! KVM: selftests: Introduce steal-time test

[Andrew Jones]

Change the pr_info's to printf's as they're already guarded by verbose,
so shouldn't be dependent on QUIET. Also remove a pointless TEST_ASSERT.

Signed-off-by: Andrew Jones <drjones@redhat.com>
---
 tools/testing/selftests/kvm/steal_time.c | 37 +++++++++++-------------
 1 file changed, 17 insertions(+), 20 deletions(-)

diff --git a/tools/testing/selftests/kvm/steal_time.c b/tools/testing/selftests/kvm/steal_time.c
index f976ac5e896a..21990d653099 100644
--- a/tools/testing/selftests/kvm/steal_time.c
+++ b/tools/testing/selftests/kvm/steal_time.c
@@ -91,18 +91,18 @@ static void steal_time_dump(struct kvm_vm *vm, uint32_t vcpuid)
 	struct kvm_steal_time *st = addr_gva2hva(vm, (ulong)st_gva[vcpuid]);
 	int i;
 
-	pr_info("VCPU%d:\n", vcpuid);
-	pr_info("    steal:     %lld\n", st->steal);
-	pr_info("    version:   %d\n", st->version);
-	pr_info("    flags:     %d\n", st->flags);
-	pr_info("    preempted: %d\n", st->preempted);
-	pr_info("    u8_pad:    ");
+	printf("VCPU%d:\n", vcpuid);
+	printf("    steal:     %lld\n", st->steal);
+	printf("    version:   %d\n", st->version);
+	printf("    flags:     %d\n", st->flags);
+	printf("    preempted: %d\n", st->preempted);
+	printf("    u8_pad:    ");
 	for (i = 0; i < 3; ++i)
-		pr_info("%d", st->u8_pad[i]);
-	pr_info("\n    pad:       ");
+		printf("%d", st->u8_pad[i]);
+	printf("\n    pad:       ");
 	for (i = 0; i < 11; ++i)
-		pr_info("%d", st->pad[i]);
-	pr_info("\n");
+		printf("%d", st->pad[i]);
+	printf("\n");
 }
 
 #elif defined(__aarch64__)
@@ -211,10 +211,10 @@ static void steal_time_dump(struct kvm_vm *vm, uint32_t vcpuid)
 {
 	struct st_time *st = addr_gva2hva(vm, (ulong)st_gva[vcpuid]);
 
-	pr_info("VCPU%d:\n", vcpuid);
-	pr_info("    rev:     %d\n", st->rev);
-	pr_info("    attr:    %d\n", st->attr);
-	pr_info("    st_time: %ld\n", st->st_time);
+	printf("VCPU%d:\n", vcpuid);
+	printf("    rev:     %d\n", st->rev);
+	printf("    attr:    %d\n", st->attr);
+	printf("    st_time: %ld\n", st->st_time);
 }
 
 #endif
@@ -326,9 +326,6 @@ int main(int ac, char **av)
 		while (get_run_delay() - run_delay < MIN_RUN_DELAY_NS);
 		pthread_join(thread, NULL);
 		run_delay = get_run_delay() - run_delay;
-		TEST_ASSERT(run_delay >= MIN_RUN_DELAY_NS,
-			    "Expected run_delay >= %ld, got %ld",
-			    MIN_RUN_DELAY_NS, run_delay);
 
 		/* Run VCPU again to confirm stolen time is consistent with run_delay */
 		run_vcpu(vm, i);
@@ -339,11 +336,11 @@ int main(int ac, char **av)
 			    run_delay, stolen_time);
 
 		if (verbose) {
-			pr_info("VCPU%d: total-stolen-time=%ld test-stolen-time=%ld", i,
+			printf("VCPU%d: total-stolen-time=%ld test-stolen-time=%ld", i,
 				guest_stolen_time[i], stolen_time);
 			if (stolen_time == run_delay)
-				pr_info(" (BONUS: guest test-stolen-time even exactly matches test-run_delay)");
-			pr_info("\n");
+				printf(" (BONUS: guest test-stolen-time even exactly matches test-run_delay)");
+			printf("\n");
 			steal_time_dump(vm, i);
 		}
 	}
-- 
2.21.1

[PATCH v2 2/2] KVM: selftests: Rework timespec functions and usage

[Andrew Jones]

The steal_time test's timespec stop condition was wrong and should have
used the timespec functions instead to avoid being wrong, but
timespec_diff had a strange interface. Rework all the timespec API and
its use.

Signed-off-by: Andrew Jones <drjones@redhat.com>
---
 .../selftests/kvm/demand_paging_test.c        | 37 ++++++++-----------
 .../testing/selftests/kvm/include/test_util.h |  3 +-
 tools/testing/selftests/kvm/lib/test_util.c   | 37 ++++++++-----------
 tools/testing/selftests/kvm/steal_time.c      |  2 +-
 4 files changed, 35 insertions(+), 44 deletions(-)

diff --git a/tools/testing/selftests/kvm/demand_paging_test.c b/tools/testing/selftests/kvm/demand_paging_test.c
index d82f7bc060c3..360cd3ea4cd6 100644
--- a/tools/testing/selftests/kvm/demand_paging_test.c
+++ b/tools/testing/selftests/kvm/demand_paging_test.c
@@ -117,8 +117,7 @@ static void *vcpu_worker(void *data)
 	struct kvm_vm *vm = args->vm;
 	int vcpu_id = args->vcpu_id;
 	struct kvm_run *run;
-	struct timespec start;
-	struct timespec end;
+	struct timespec start, end, ts_diff;
 
 	vcpu_args_set(vm, vcpu_id, 1, vcpu_id);
 	run = vcpu_state(vm, vcpu_id);
@@ -135,9 +134,9 @@ static void *vcpu_worker(void *data)
 	}
 
 	clock_gettime(CLOCK_MONOTONIC, &end);
-	PER_VCPU_DEBUG("vCPU %d execution time: %lld.%.9lds\n", vcpu_id,
-		       (long long)(timespec_diff(start, end).tv_sec),
-		       timespec_diff(start, end).tv_nsec);
+	ts_diff = timespec_sub(end, start);
+	PER_VCPU_DEBUG("vCPU %d execution time: %ld.%.9lds\n", vcpu_id,
+		       ts_diff.tv_sec, ts_diff.tv_nsec);
 
 	return NULL;
 }
@@ -201,8 +200,8 @@ static int handle_uffd_page_request(int uffd, uint64_t addr)
 
 	clock_gettime(CLOCK_MONOTONIC, &end);
 
-	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%lld ns\n", tid,
-		       (long long)timespec_to_ns(timespec_diff(start, end)));
+	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%ld ns\n", tid,
+		       timespec_to_ns(timespec_sub(end, start)));
 	PER_PAGE_DEBUG("Paged in %ld bytes at 0x%lx from thread %d\n",
 		       host_page_size, addr, tid);
 
@@ -224,8 +223,7 @@ static void *uffd_handler_thread_fn(void *arg)
 	int pipefd = uffd_args->pipefd;
 	useconds_t delay = uffd_args->delay;
 	int64_t pages = 0;
-	struct timespec start;
-	struct timespec end;
+	struct timespec start, end, ts_diff;
 
 	clock_gettime(CLOCK_MONOTONIC, &start);
 	while (!quit_uffd_thread) {
@@ -295,11 +293,10 @@ static void *uffd_handler_thread_fn(void *arg)
 	}
 
 	clock_gettime(CLOCK_MONOTONIC, &end);
-	PER_VCPU_DEBUG("userfaulted %ld pages over %lld.%.9lds. (%f/sec)\n",
-		       pages, (long long)(timespec_diff(start, end).tv_sec),
-		       timespec_diff(start, end).tv_nsec, pages /
-		       ((double)timespec_diff(start, end).tv_sec +
-			(double)timespec_diff(start, end).tv_nsec / 100000000.0));
+	ts_diff = timespec_sub(end, start);
+	PER_VCPU_DEBUG("userfaulted %ld pages over %ld.%.9lds. (%f/sec)\n",
+		       pages, ts_diff.tv_sec, ts_diff.tv_nsec,
+		       pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
 
 	return NULL;
 }
@@ -360,13 +357,12 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
 	pthread_t *vcpu_threads;
 	pthread_t *uffd_handler_threads = NULL;
 	struct uffd_handler_args *uffd_args = NULL;
+	struct timespec start, end, ts_diff;
 	int *pipefds = NULL;
 	struct kvm_vm *vm;
 	uint64_t guest_num_pages;
 	int vcpu_id;
 	int r;
-	struct timespec start;
-	struct timespec end;
 
 	vm = create_vm(mode, vcpus, vcpu_memory_bytes);
 
@@ -514,12 +510,11 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
 		}
 	}
 
-	pr_info("Total guest execution time: %lld.%.9lds\n",
-		(long long)(timespec_diff(start, end).tv_sec),
-		timespec_diff(start, end).tv_nsec);
+	ts_diff = timespec_sub(end, start);
+	pr_info("Total guest execution time: %ld.%.9lds\n",
+		ts_diff.tv_sec, ts_diff.tv_nsec);
 	pr_info("Overall demand paging rate: %f pgs/sec\n",
-		guest_num_pages / ((double)timespec_diff(start, end).tv_sec +
-		(double)timespec_diff(start, end).tv_nsec / 100000000.0));
+		guest_num_pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
 
 	ucall_uninit(vm);
 	kvm_vm_free(vm);
diff --git a/tools/testing/selftests/kvm/include/test_util.h b/tools/testing/selftests/kvm/include/test_util.h
index f588ad1403f1..5eb01bf51b86 100644
--- a/tools/testing/selftests/kvm/include/test_util.h
+++ b/tools/testing/selftests/kvm/include/test_util.h
@@ -61,7 +61,8 @@ void test_assert(bool exp, const char *exp_str,
 size_t parse_size(const char *size);
 
 int64_t timespec_to_ns(struct timespec ts);
-struct timespec timespec_diff(struct timespec start, struct timespec end);
 struct timespec timespec_add_ns(struct timespec ts, int64_t ns);
+struct timespec timespec_add(struct timespec ts1, struct timespec ts2);
+struct timespec timespec_sub(struct timespec ts1, struct timespec ts2);
 
 #endif /* SELFTEST_KVM_TEST_UTIL_H */
diff --git a/tools/testing/selftests/kvm/lib/test_util.c b/tools/testing/selftests/kvm/lib/test_util.c
index ee12c4b9ae05..689e97c27ee2 100644
--- a/tools/testing/selftests/kvm/lib/test_util.c
+++ b/tools/testing/selftests/kvm/lib/test_util.c
@@ -56,36 +56,31 @@ int64_t timespec_to_ns(struct timespec ts)
 	return (int64_t)ts.tv_nsec + 1000000000LL * (int64_t)ts.tv_sec;
 }
 
-struct timespec timespec_diff(struct timespec start, struct timespec end)
-{
-	struct timespec temp;
-
-	if ((end.tv_nsec - start.tv_nsec) < 0) {
-		temp.tv_sec = end.tv_sec - start.tv_sec - 1;
-		temp.tv_nsec = 1000000000LL + end.tv_nsec - start.tv_nsec;
-	} else {
-		temp.tv_sec = end.tv_sec - start.tv_sec;
-		temp.tv_nsec = end.tv_nsec - start.tv_nsec;
-	}
-
-	return temp;
-}
-
 struct timespec timespec_add_ns(struct timespec ts, int64_t ns)
 {
 	struct timespec res;
 
-	res.tv_sec = ts.tv_sec;
 	res.tv_nsec = ts.tv_nsec + ns;
-
-	if (res.tv_nsec > 1000000000UL) {
-		res.tv_sec += 1;
-		res.tv_nsec -= 1000000000UL;
-	}
+	res.tv_sec = ts.tv_sec + res.tv_nsec / 1000000000LL;
+	res.tv_nsec %= 1000000000LL;
 
 	return res;
 }
 
+struct timespec timespec_add(struct timespec ts1, struct timespec ts2)
+{
+	int64_t ns1 = timespec_to_ns(ts1);
+	int64_t ns2 = timespec_to_ns(ts2);
+	return timespec_add_ns((struct timespec){0}, ns1 + ns2);
+}
+
+struct timespec timespec_sub(struct timespec ts1, struct timespec ts2)
+{
+	int64_t ns1 = timespec_to_ns(ts1);
+	int64_t ns2 = timespec_to_ns(ts2);
+	return timespec_add_ns((struct timespec){0}, ns1 - ns2);
+}
+
 void print_skip(const char *fmt, ...)
 {
 	va_list ap;
diff --git a/tools/testing/selftests/kvm/steal_time.c b/tools/testing/selftests/kvm/steal_time.c
index 21990d653099..86f30eda0ae7 100644
--- a/tools/testing/selftests/kvm/steal_time.c
+++ b/tools/testing/selftests/kvm/steal_time.c
@@ -242,7 +242,7 @@ static void *do_steal_time(void *arg)
 
 	while (1) {
 		clock_gettime(CLOCK_MONOTONIC, &ts);
-		if (ts.tv_sec > stop.tv_sec || ts.tv_nsec >= stop.tv_nsec)
+		if (timespec_to_ns(timespec_sub(ts, stop)) >= 0)
 			break;
 	}
 
-- 
2.21.1

Re: [PATCH v2 2/2] KVM: selftests: Rework timespec functions and usage

[Paolo Bonzini]

On 16/03/20 18:37, Andrew Jones wrote:
> The steal_time test's timespec stop condition was wrong and should have
> used the timespec functions instead to avoid being wrong, but
> timespec_diff had a strange interface. Rework all the timespec API and
> its use.
> 
> Signed-off-by: Andrew Jones <drjones@redhat.com>

Queued this one, I have already pushed the test to kvm/next so the
"fixup!" commit cannot be squashed.  But I don't really mind the code as
it looks in kvm/next.

Paolo

> ---
>  .../selftests/kvm/demand_paging_test.c        | 37 ++++++++-----------
>  .../testing/selftests/kvm/include/test_util.h |  3 +-
>  tools/testing/selftests/kvm/lib/test_util.c   | 37 ++++++++-----------
>  tools/testing/selftests/kvm/steal_time.c      |  2 +-
>  4 files changed, 35 insertions(+), 44 deletions(-)
> 
> diff --git a/tools/testing/selftests/kvm/demand_paging_test.c b/tools/testing/selftests/kvm/demand_paging_test.c
> index d82f7bc060c3..360cd3ea4cd6 100644
> --- a/tools/testing/selftests/kvm/demand_paging_test.c
> +++ b/tools/testing/selftests/kvm/demand_paging_test.c
> @@ -117,8 +117,7 @@ static void *vcpu_worker(void *data)
>  	struct kvm_vm *vm = args->vm;
>  	int vcpu_id = args->vcpu_id;
>  	struct kvm_run *run;
> -	struct timespec start;
> -	struct timespec end;
> +	struct timespec start, end, ts_diff;
>  
>  	vcpu_args_set(vm, vcpu_id, 1, vcpu_id);
>  	run = vcpu_state(vm, vcpu_id);
> @@ -135,9 +134,9 @@ static void *vcpu_worker(void *data)
>  	}
>  
>  	clock_gettime(CLOCK_MONOTONIC, &end);
> -	PER_VCPU_DEBUG("vCPU %d execution time: %lld.%.9lds\n", vcpu_id,
> -		       (long long)(timespec_diff(start, end).tv_sec),
> -		       timespec_diff(start, end).tv_nsec);
> +	ts_diff = timespec_sub(end, start);
> +	PER_VCPU_DEBUG("vCPU %d execution time: %ld.%.9lds\n", vcpu_id,
> +		       ts_diff.tv_sec, ts_diff.tv_nsec);
>  
>  	return NULL;
>  }
> @@ -201,8 +200,8 @@ static int handle_uffd_page_request(int uffd, uint64_t addr)
>  
>  	clock_gettime(CLOCK_MONOTONIC, &end);
>  
> -	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%lld ns\n", tid,
> -		       (long long)timespec_to_ns(timespec_diff(start, end)));
> +	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%ld ns\n", tid,
> +		       timespec_to_ns(timespec_sub(end, start)));
>  	PER_PAGE_DEBUG("Paged in %ld bytes at 0x%lx from thread %d\n",
>  		       host_page_size, addr, tid);
>  
> @@ -224,8 +223,7 @@ static void *uffd_handler_thread_fn(void *arg)
>  	int pipefd = uffd_args->pipefd;
>  	useconds_t delay = uffd_args->delay;
>  	int64_t pages = 0;
> -	struct timespec start;
> -	struct timespec end;
> +	struct timespec start, end, ts_diff;
>  
>  	clock_gettime(CLOCK_MONOTONIC, &start);
>  	while (!quit_uffd_thread) {
> @@ -295,11 +293,10 @@ static void *uffd_handler_thread_fn(void *arg)
>  	}
>  
>  	clock_gettime(CLOCK_MONOTONIC, &end);
> -	PER_VCPU_DEBUG("userfaulted %ld pages over %lld.%.9lds. (%f/sec)\n",
> -		       pages, (long long)(timespec_diff(start, end).tv_sec),
> -		       timespec_diff(start, end).tv_nsec, pages /
> -		       ((double)timespec_diff(start, end).tv_sec +
> -			(double)timespec_diff(start, end).tv_nsec / 100000000.0));
> +	ts_diff = timespec_sub(end, start);
> +	PER_VCPU_DEBUG("userfaulted %ld pages over %ld.%.9lds. (%f/sec)\n",
> +		       pages, ts_diff.tv_sec, ts_diff.tv_nsec,
> +		       pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
>  
>  	return NULL;
>  }
> @@ -360,13 +357,12 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
>  	pthread_t *vcpu_threads;
>  	pthread_t *uffd_handler_threads = NULL;
>  	struct uffd_handler_args *uffd_args = NULL;
> +	struct timespec start, end, ts_diff;
>  	int *pipefds = NULL;
>  	struct kvm_vm *vm;
>  	uint64_t guest_num_pages;
>  	int vcpu_id;
>  	int r;
> -	struct timespec start;
> -	struct timespec end;
>  
>  	vm = create_vm(mode, vcpus, vcpu_memory_bytes);
>  
> @@ -514,12 +510,11 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
>  		}
>  	}
>  
> -	pr_info("Total guest execution time: %lld.%.9lds\n",
> -		(long long)(timespec_diff(start, end).tv_sec),
> -		timespec_diff(start, end).tv_nsec);
> +	ts_diff = timespec_sub(end, start);
> +	pr_info("Total guest execution time: %ld.%.9lds\n",
> +		ts_diff.tv_sec, ts_diff.tv_nsec);
>  	pr_info("Overall demand paging rate: %f pgs/sec\n",
> -		guest_num_pages / ((double)timespec_diff(start, end).tv_sec +
> -		(double)timespec_diff(start, end).tv_nsec / 100000000.0));
> +		guest_num_pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
>  
>  	ucall_uninit(vm);
>  	kvm_vm_free(vm);
> diff --git a/tools/testing/selftests/kvm/include/test_util.h b/tools/testing/selftests/kvm/include/test_util.h
> index f588ad1403f1..5eb01bf51b86 100644
> --- a/tools/testing/selftests/kvm/include/test_util.h
> +++ b/tools/testing/selftests/kvm/include/test_util.h
> @@ -61,7 +61,8 @@ void test_assert(bool exp, const char *exp_str,
>  size_t parse_size(const char *size);
>  
>  int64_t timespec_to_ns(struct timespec ts);
> -struct timespec timespec_diff(struct timespec start, struct timespec end);
>  struct timespec timespec_add_ns(struct timespec ts, int64_t ns);
> +struct timespec timespec_add(struct timespec ts1, struct timespec ts2);
> +struct timespec timespec_sub(struct timespec ts1, struct timespec ts2);
>  
>  #endif /* SELFTEST_KVM_TEST_UTIL_H */
> diff --git a/tools/testing/selftests/kvm/lib/test_util.c b/tools/testing/selftests/kvm/lib/test_util.c
> index ee12c4b9ae05..689e97c27ee2 100644
> --- a/tools/testing/selftests/kvm/lib/test_util.c
> +++ b/tools/testing/selftests/kvm/lib/test_util.c
> @@ -56,36 +56,31 @@ int64_t timespec_to_ns(struct timespec ts)
>  	return (int64_t)ts.tv_nsec + 1000000000LL * (int64_t)ts.tv_sec;
>  }
>  
> -struct timespec timespec_diff(struct timespec start, struct timespec end)
> -{
> -	struct timespec temp;
> -
> -	if ((end.tv_nsec - start.tv_nsec) < 0) {
> -		temp.tv_sec = end.tv_sec - start.tv_sec - 1;
> -		temp.tv_nsec = 1000000000LL + end.tv_nsec - start.tv_nsec;
> -	} else {
> -		temp.tv_sec = end.tv_sec - start.tv_sec;
> -		temp.tv_nsec = end.tv_nsec - start.tv_nsec;
> -	}
> -
> -	return temp;
> -}
> -
>  struct timespec timespec_add_ns(struct timespec ts, int64_t ns)
>  {
>  	struct timespec res;
>  
> -	res.tv_sec = ts.tv_sec;
>  	res.tv_nsec = ts.tv_nsec + ns;
> -
> -	if (res.tv_nsec > 1000000000UL) {
> -		res.tv_sec += 1;
> -		res.tv_nsec -= 1000000000UL;
> -	}
> +	res.tv_sec = ts.tv_sec + res.tv_nsec / 1000000000LL;
> +	res.tv_nsec %= 1000000000LL;
>  
>  	return res;
>  }
>  
> +struct timespec timespec_add(struct timespec ts1, struct timespec ts2)
> +{
> +	int64_t ns1 = timespec_to_ns(ts1);
> +	int64_t ns2 = timespec_to_ns(ts2);
> +	return timespec_add_ns((struct timespec){0}, ns1 + ns2);
> +}
> +
> +struct timespec timespec_sub(struct timespec ts1, struct timespec ts2)
> +{
> +	int64_t ns1 = timespec_to_ns(ts1);
> +	int64_t ns2 = timespec_to_ns(ts2);
> +	return timespec_add_ns((struct timespec){0}, ns1 - ns2);
> +}
> +
>  void print_skip(const char *fmt, ...)
>  {
>  	va_list ap;
> diff --git a/tools/testing/selftests/kvm/steal_time.c b/tools/testing/selftests/kvm/steal_time.c
> index 21990d653099..86f30eda0ae7 100644
> --- a/tools/testing/selftests/kvm/steal_time.c
> +++ b/tools/testing/selftests/kvm/steal_time.c
> @@ -242,7 +242,7 @@ static void *do_steal_time(void *arg)
>  
>  	while (1) {
>  		clock_gettime(CLOCK_MONOTONIC, &ts);
> -		if (ts.tv_sec > stop.tv_sec || ts.tv_nsec >= stop.tv_nsec)
> +		if (timespec_to_ns(timespec_sub(ts, stop)) >= 0)
>  			break;
>  	}
>  
> 

Re: [PATCH v2 2/2] KVM: selftests: Rework timespec functions and usage

[Andrew Jones]

On Wed, Mar 18, 2020 at 02:10:25PM +0100, Paolo Bonzini wrote:
> On 16/03/20 18:37, Andrew Jones wrote:
> > The steal_time test's timespec stop condition was wrong and should have
> > used the timespec functions instead to avoid being wrong, but
> > timespec_diff had a strange interface. Rework all the timespec API and
> > its use.
> > 
> > Signed-off-by: Andrew Jones <drjones@redhat.com>
> 
> Queued this one,

I don't see this in queue or next.

> I have already pushed the test to kvm/next so the
> "fixup!" commit cannot be squashed.  But I don't really mind the code as
> it looks in kvm/next.

The previous patch isn't a huge deal, but it's more than a cleanup,
because if somebody wants to use QUIET when compiling, but then --verbose
when executing, they won't get any verbose output. And the removed,
useless assert is truly useless.

Thanks,
drew

> 
> Paolo
> 
> > ---
> >  .../selftests/kvm/demand_paging_test.c        | 37 ++++++++-----------
> >  .../testing/selftests/kvm/include/test_util.h |  3 +-
> >  tools/testing/selftests/kvm/lib/test_util.c   | 37 ++++++++-----------
> >  tools/testing/selftests/kvm/steal_time.c      |  2 +-
> >  4 files changed, 35 insertions(+), 44 deletions(-)
> > 
> > diff --git a/tools/testing/selftests/kvm/demand_paging_test.c b/tools/testing/selftests/kvm/demand_paging_test.c
> > index d82f7bc060c3..360cd3ea4cd6 100644
> > --- a/tools/testing/selftests/kvm/demand_paging_test.c
> > +++ b/tools/testing/selftests/kvm/demand_paging_test.c
> > @@ -117,8 +117,7 @@ static void *vcpu_worker(void *data)
> >  	struct kvm_vm *vm = args->vm;
> >  	int vcpu_id = args->vcpu_id;
> >  	struct kvm_run *run;
> > -	struct timespec start;
> > -	struct timespec end;
> > +	struct timespec start, end, ts_diff;
> >  
> >  	vcpu_args_set(vm, vcpu_id, 1, vcpu_id);
> >  	run = vcpu_state(vm, vcpu_id);
> > @@ -135,9 +134,9 @@ static void *vcpu_worker(void *data)
> >  	}
> >  
> >  	clock_gettime(CLOCK_MONOTONIC, &end);
> > -	PER_VCPU_DEBUG("vCPU %d execution time: %lld.%.9lds\n", vcpu_id,
> > -		       (long long)(timespec_diff(start, end).tv_sec),
> > -		       timespec_diff(start, end).tv_nsec);
> > +	ts_diff = timespec_sub(end, start);
> > +	PER_VCPU_DEBUG("vCPU %d execution time: %ld.%.9lds\n", vcpu_id,
> > +		       ts_diff.tv_sec, ts_diff.tv_nsec);
> >  
> >  	return NULL;
> >  }
> > @@ -201,8 +200,8 @@ static int handle_uffd_page_request(int uffd, uint64_t addr)
> >  
> >  	clock_gettime(CLOCK_MONOTONIC, &end);
> >  
> > -	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%lld ns\n", tid,
> > -		       (long long)timespec_to_ns(timespec_diff(start, end)));
> > +	PER_PAGE_DEBUG("UFFDIO_COPY %d \t%ld ns\n", tid,
> > +		       timespec_to_ns(timespec_sub(end, start)));
> >  	PER_PAGE_DEBUG("Paged in %ld bytes at 0x%lx from thread %d\n",
> >  		       host_page_size, addr, tid);
> >  
> > @@ -224,8 +223,7 @@ static void *uffd_handler_thread_fn(void *arg)
> >  	int pipefd = uffd_args->pipefd;
> >  	useconds_t delay = uffd_args->delay;
> >  	int64_t pages = 0;
> > -	struct timespec start;
> > -	struct timespec end;
> > +	struct timespec start, end, ts_diff;
> >  
> >  	clock_gettime(CLOCK_MONOTONIC, &start);
> >  	while (!quit_uffd_thread) {
> > @@ -295,11 +293,10 @@ static void *uffd_handler_thread_fn(void *arg)
> >  	}
> >  
> >  	clock_gettime(CLOCK_MONOTONIC, &end);
> > -	PER_VCPU_DEBUG("userfaulted %ld pages over %lld.%.9lds. (%f/sec)\n",
> > -		       pages, (long long)(timespec_diff(start, end).tv_sec),
> > -		       timespec_diff(start, end).tv_nsec, pages /
> > -		       ((double)timespec_diff(start, end).tv_sec +
> > -			(double)timespec_diff(start, end).tv_nsec / 100000000.0));
> > +	ts_diff = timespec_sub(end, start);
> > +	PER_VCPU_DEBUG("userfaulted %ld pages over %ld.%.9lds. (%f/sec)\n",
> > +		       pages, ts_diff.tv_sec, ts_diff.tv_nsec,
> > +		       pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
> >  
> >  	return NULL;
> >  }
> > @@ -360,13 +357,12 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
> >  	pthread_t *vcpu_threads;
> >  	pthread_t *uffd_handler_threads = NULL;
> >  	struct uffd_handler_args *uffd_args = NULL;
> > +	struct timespec start, end, ts_diff;
> >  	int *pipefds = NULL;
> >  	struct kvm_vm *vm;
> >  	uint64_t guest_num_pages;
> >  	int vcpu_id;
> >  	int r;
> > -	struct timespec start;
> > -	struct timespec end;
> >  
> >  	vm = create_vm(mode, vcpus, vcpu_memory_bytes);
> >  
> > @@ -514,12 +510,11 @@ static void run_test(enum vm_guest_mode mode, bool use_uffd,
> >  		}
> >  	}
> >  
> > -	pr_info("Total guest execution time: %lld.%.9lds\n",
> > -		(long long)(timespec_diff(start, end).tv_sec),
> > -		timespec_diff(start, end).tv_nsec);
> > +	ts_diff = timespec_sub(end, start);
> > +	pr_info("Total guest execution time: %ld.%.9lds\n",
> > +		ts_diff.tv_sec, ts_diff.tv_nsec);
> >  	pr_info("Overall demand paging rate: %f pgs/sec\n",
> > -		guest_num_pages / ((double)timespec_diff(start, end).tv_sec +
> > -		(double)timespec_diff(start, end).tv_nsec / 100000000.0));
> > +		guest_num_pages / ((double)ts_diff.tv_sec + (double)ts_diff.tv_nsec / 100000000.0));
> >  
> >  	ucall_uninit(vm);
> >  	kvm_vm_free(vm);
> > diff --git a/tools/testing/selftests/kvm/include/test_util.h b/tools/testing/selftests/kvm/include/test_util.h
> > index f588ad1403f1..5eb01bf51b86 100644
> > --- a/tools/testing/selftests/kvm/include/test_util.h
> > +++ b/tools/testing/selftests/kvm/include/test_util.h
> > @@ -61,7 +61,8 @@ void test_assert(bool exp, const char *exp_str,
> >  size_t parse_size(const char *size);
> >  
> >  int64_t timespec_to_ns(struct timespec ts);
> > -struct timespec timespec_diff(struct timespec start, struct timespec end);
> >  struct timespec timespec_add_ns(struct timespec ts, int64_t ns);
> > +struct timespec timespec_add(struct timespec ts1, struct timespec ts2);
> > +struct timespec timespec_sub(struct timespec ts1, struct timespec ts2);
> >  
> >  #endif /* SELFTEST_KVM_TEST_UTIL_H */
> > diff --git a/tools/testing/selftests/kvm/lib/test_util.c b/tools/testing/selftests/kvm/lib/test_util.c
> > index ee12c4b9ae05..689e97c27ee2 100644
> > --- a/tools/testing/selftests/kvm/lib/test_util.c
> > +++ b/tools/testing/selftests/kvm/lib/test_util.c
> > @@ -56,36 +56,31 @@ int64_t timespec_to_ns(struct timespec ts)
> >  	return (int64_t)ts.tv_nsec + 1000000000LL * (int64_t)ts.tv_sec;
> >  }
> >  
> > -struct timespec timespec_diff(struct timespec start, struct timespec end)
> > -{
> > -	struct timespec temp;
> > -
> > -	if ((end.tv_nsec - start.tv_nsec) < 0) {
> > -		temp.tv_sec = end.tv_sec - start.tv_sec - 1;
> > -		temp.tv_nsec = 1000000000LL + end.tv_nsec - start.tv_nsec;
> > -	} else {
> > -		temp.tv_sec = end.tv_sec - start.tv_sec;
> > -		temp.tv_nsec = end.tv_nsec - start.tv_nsec;
> > -	}
> > -
> > -	return temp;
> > -}
> > -
> >  struct timespec timespec_add_ns(struct timespec ts, int64_t ns)
> >  {
> >  	struct timespec res;
> >  
> > -	res.tv_sec = ts.tv_sec;
> >  	res.tv_nsec = ts.tv_nsec + ns;
> > -
> > -	if (res.tv_nsec > 1000000000UL) {
> > -		res.tv_sec += 1;
> > -		res.tv_nsec -= 1000000000UL;
> > -	}
> > +	res.tv_sec = ts.tv_sec + res.tv_nsec / 1000000000LL;
> > +	res.tv_nsec %= 1000000000LL;
> >  
> >  	return res;
> >  }
> >  
> > +struct timespec timespec_add(struct timespec ts1, struct timespec ts2)
> > +{
> > +	int64_t ns1 = timespec_to_ns(ts1);
> > +	int64_t ns2 = timespec_to_ns(ts2);
> > +	return timespec_add_ns((struct timespec){0}, ns1 + ns2);
> > +}
> > +
> > +struct timespec timespec_sub(struct timespec ts1, struct timespec ts2)
> > +{
> > +	int64_t ns1 = timespec_to_ns(ts1);
> > +	int64_t ns2 = timespec_to_ns(ts2);
> > +	return timespec_add_ns((struct timespec){0}, ns1 - ns2);
> > +}
> > +
> >  void print_skip(const char *fmt, ...)
> >  {
> >  	va_list ap;
> > diff --git a/tools/testing/selftests/kvm/steal_time.c b/tools/testing/selftests/kvm/steal_time.c
> > index 21990d653099..86f30eda0ae7 100644
> > --- a/tools/testing/selftests/kvm/steal_time.c
> > +++ b/tools/testing/selftests/kvm/steal_time.c
> > @@ -242,7 +242,7 @@ static void *do_steal_time(void *arg)
> >  
> >  	while (1) {
> >  		clock_gettime(CLOCK_MONOTONIC, &ts);
> > -		if (ts.tv_sec > stop.tv_sec || ts.tv_nsec >= stop.tv_nsec)
> > +		if (timespec_to_ns(timespec_sub(ts, stop)) >= 0)
> >  			break;
> >  	}
> >  
> > 
>