| Message ID | 20230607224520.4164598-1-aaronlewis@google.com (mailing list archive) |
|---|---|
| Headers | show |
| Series | Add printf and formatted asserts in the guest | expand |
On Wed, Jun 07, 2023, Aaron Lewis wrote: > Extend the ucall framework to offer GUEST_PRINTF() and GUEST_ASSERT_FMT() > in selftests. This will allow for better and easier guest debugging. This. Is. Awesome. Seriously, this is amazing! I have one or two nits, but theyre so minor I already forgot what they were. The one thing I think we should change is the final output of the assert. Rather than report the host TEST_FAIL as the assert: # ./svm_nested_soft_inject_test Running soft int test ==== Test Assertion Failure ==== x86_64/svm_nested_soft_inject_test.c:191: false pid=169827 tid=169827 errno=4 - Interrupted system call 1 0x0000000000401b52: run_test at svm_nested_soft_inject_test.c:191 2 0x00000000004017d2: main at svm_nested_soft_inject_test.c:212 3 0x00000000004159d3: __libc_start_call_main at libc-start.o:? 4 0x000000000041701f: __libc_start_main_impl at ??:? 5 0x0000000000401660: _start at ??:? Failed guest assert: regs->rip != (unsigned long)l2_guest_code_int at x86_64/svm_nested_soft_inject_test.c:39 Expected IRQ at RIP 0x401e80, received IRQ at 0x401e80 show the guest assert as the primary assert. Running soft int test ==== Test Assertion Failure ==== x86_64/svm_nested_soft_inject_test.c:39: regs->rip != (unsigned long)l2_guest_code_int pid=214104 tid=214104 errno=4 - Interrupted system call 1 0x0000000000401b35: run_test at svm_nested_soft_inject_test.c:191 2 0x00000000004017d2: main at svm_nested_soft_inject_test.c:212 3 0x0000000000415b03: __libc_start_call_main at libc-start.o:? 4 0x000000000041714f: __libc_start_main_impl at ??:? 5 0x0000000000401660: _start at ??:? Expected IRQ at RIP 0x401e50, received IRQ at 0x401e50 That way users don't have to manually find the "real" assert. Ditto for any kind of automated reporting. The site of the test_fail() invocation in the host is still captured in the stack trace (though that too could be something to fix over time), so unless I'm missing something, there's no information lost. The easiest thing I can think of is to add a second buffer to hold the exp+file+line. Then, test_assert() just needs to skip that particular line of formatting. If you don't object, I'll post a v4 with the below folded in somewhere (after more testing), and put this on the fast track for 6.6. Side topic, if anyone lurking out there wants an easy (but tedious and boring) starter project, we should convert all tests to the newfangled formatting and drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. --- .../selftests/kvm/include/ucall_common.h | 19 ++++++++--------- tools/testing/selftests/kvm/lib/assert.c | 13 +++++++----- .../testing/selftests/kvm/lib/ucall_common.c | 21 +++++++++++++++++++ 3 files changed, 38 insertions(+), 15 deletions(-) diff --git a/tools/testing/selftests/kvm/include/ucall_common.h b/tools/testing/selftests/kvm/include/ucall_common.h index b4f4c88e8d84..3bc4e62bec1b 100644 --- a/tools/testing/selftests/kvm/include/ucall_common.h +++ b/tools/testing/selftests/kvm/include/ucall_common.h @@ -25,6 +25,7 @@ struct ucall { uint64_t cmd; uint64_t args[UCALL_MAX_ARGS]; char buffer[UCALL_BUFFER_LEN]; + char aux_buffer[UCALL_BUFFER_LEN]; /* Host virtual address of this struct. */ struct ucall *hva; @@ -36,6 +37,8 @@ void *ucall_arch_get_ucall(struct kvm_vcpu *vcpu); void ucall(uint64_t cmd, int nargs, ...); void ucall_fmt(uint64_t cmd, const char *fmt, ...); +void ucall_assert(uint64_t cmd, const char *exp, const char *file, + unsigned int line, const char *fmt, ...); uint64_t get_ucall(struct kvm_vcpu *vcpu, struct ucall *uc); void ucall_init(struct kvm_vm *vm, vm_paddr_t mmio_gpa); int ucall_nr_pages_required(uint64_t page_size); @@ -63,15 +66,10 @@ enum guest_assert_builtin_args { GUEST_ASSERT_BUILTIN_NARGS }; -#define __GUEST_ASSERT_FMT(_condition, _str, _fmt, _args...) \ -do { \ - char fmt[UCALL_BUFFER_LEN]; \ - \ - if (!(_condition)) { \ - guest_snprintf(fmt, sizeof(fmt), "%s\n %s", \ - "Failed guest assert: " _str " at %s:%ld", _fmt); \ - ucall_fmt(UCALL_ABORT, fmt, __FILE__, __LINE__, ##_args); \ - } \ +#define __GUEST_ASSERT_FMT(_condition, _str, _fmt, _args...) \ +do { \ + if (!(_condition)) \ + ucall_assert(UCALL_ABORT, _str, __FILE__, __LINE__, _fmt, ##_args); \ } while (0) #define GUEST_ASSERT_FMT(_condition, _fmt, _args...) \ @@ -102,7 +100,8 @@ do { \ #define GUEST_ASSERT_EQ(a, b) __GUEST_ASSERT((a) == (b), #a " == " #b, 2, a, b) -#define REPORT_GUEST_ASSERT_FMT(_ucall) TEST_FAIL("%s", _ucall.buffer) +#define REPORT_GUEST_ASSERT_FMT(ucall) \ + test_assert(false, (ucall).aux_buffer, NULL, 0, "%s", (ucall).buffer); #define __REPORT_GUEST_ASSERT(_ucall, fmt, _args...) \ TEST_FAIL("%s at %s:%ld\n" fmt, \ diff --git a/tools/testing/selftests/kvm/lib/assert.c b/tools/testing/selftests/kvm/lib/assert.c index 2bd25b191d15..74d94a34cf1a 100644 --- a/tools/testing/selftests/kvm/lib/assert.c +++ b/tools/testing/selftests/kvm/lib/assert.c @@ -75,11 +75,14 @@ test_assert(bool exp, const char *exp_str, if (!(exp)) { va_start(ap, fmt); - fprintf(stderr, "==== Test Assertion Failure ====\n" - " %s:%u: %s\n" - " pid=%d tid=%d errno=%d - %s\n", - file, line, exp_str, getpid(), _gettid(), - errno, strerror(errno)); + fprintf(stderr, "==== Test Assertion Failure ====\n"); + /* If @file is NULL, @exp_str contains a preformatted string. */ + if (file) + fprintf(stderr, " %s:%u: %s\n", file, line, exp_str); + else + fprintf(stderr, " %s\n", exp_str); + fprintf(stderr, " pid=%d tid=%d errno=%d - %s\n", + getpid(), _gettid(), errno, strerror(errno)); test_dump_stack(); if (fmt) { fputs(" ", stderr); diff --git a/tools/testing/selftests/kvm/lib/ucall_common.c b/tools/testing/selftests/kvm/lib/ucall_common.c index b507db91139b..e7741aadf2ce 100644 --- a/tools/testing/selftests/kvm/lib/ucall_common.c +++ b/tools/testing/selftests/kvm/lib/ucall_common.c @@ -75,6 +75,27 @@ static void ucall_free(struct ucall *uc) clear_bit(uc - ucall_pool->ucalls, ucall_pool->in_use); } +void ucall_assert(uint64_t cmd, const char *exp, const char *file, + unsigned int line, const char *fmt, ...) +{ + struct ucall *uc; + va_list va; + + uc = ucall_alloc(); + uc->cmd = cmd; + + guest_snprintf(uc->aux_buffer, sizeof(uc->aux_buffer), + "%s:%u: %s", file, line, exp); + + va_start(va, fmt); + guest_vsnprintf(uc->buffer, UCALL_BUFFER_LEN, fmt, va); + va_end(va); + + ucall_arch_do_ucall((vm_vaddr_t)uc->hva); + + ucall_free(uc); +} + void ucall_fmt(uint64_t cmd, const char *fmt, ...) { struct ucall *uc; base-commit: 8dc29dfc010293957c5ca24271748a3c8f047a76 --
在 2023/7/27 06:41, Sean Christopherson 写道: > On Wed, Jun 07, 2023, Aaron Lewis wrote: >> Extend the ucall framework to offer GUEST_PRINTF() and GUEST_ASSERT_FMT() >> in selftests. This will allow for better and easier guest debugging. > > This. Is. Awesome. Seriously, this is amazing! > > I have one or two nits, but theyre so minor I already forgot what they were. > > The one thing I think we should change is the final output of the assert. Rather > than report the host TEST_FAIL as the assert: > > # ./svm_nested_soft_inject_test > Running soft int test > ==== Test Assertion Failure ==== > x86_64/svm_nested_soft_inject_test.c:191: false > pid=169827 tid=169827 errno=4 - Interrupted system call > 1 0x0000000000401b52: run_test at svm_nested_soft_inject_test.c:191 > 2 0x00000000004017d2: main at svm_nested_soft_inject_test.c:212 > 3 0x00000000004159d3: __libc_start_call_main at libc-start.o:? > 4 0x000000000041701f: __libc_start_main_impl at ??:? > 5 0x0000000000401660: _start at ??:? > Failed guest assert: regs->rip != (unsigned long)l2_guest_code_int at x86_64/svm_nested_soft_inject_test.c:39 > Expected IRQ at RIP 0x401e80, received IRQ at 0x401e80 > > show the guest assert as the primary assert. > > Running soft int test > ==== Test Assertion Failure ==== > x86_64/svm_nested_soft_inject_test.c:39: regs->rip != (unsigned long)l2_guest_code_int > pid=214104 tid=214104 errno=4 - Interrupted system call > 1 0x0000000000401b35: run_test at svm_nested_soft_inject_test.c:191 > 2 0x00000000004017d2: main at svm_nested_soft_inject_test.c:212 > 3 0x0000000000415b03: __libc_start_call_main at libc-start.o:? > 4 0x000000000041714f: __libc_start_main_impl at ??:? > 5 0x0000000000401660: _start at ??:? > Expected IRQ at RIP 0x401e50, received IRQ at 0x401e50 > > That way users don't have to manually find the "real" assert. Ditto for any kind > of automated reporting. The site of the test_fail() invocation in the host is > still captured in the stack trace (though that too could be something to fix over > time), so unless I'm missing something, there's no information lost. > > The easiest thing I can think of is to add a second buffer to hold the exp+file+line. > Then, test_assert() just needs to skip that particular line of formatting. > > If you don't object, I'll post a v4 with the below folded in somewhere (after > more testing), and put this on the fast track for 6.6. > > Side topic, if anyone lurking out there wants an easy (but tedious and boring) > starter project, we should convert all tests to the newfangled formatting and > drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() > and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. I'd be happy to get the job done. However, before I proceed, could you please provide a more detailed example or further guidance on the desired formatting and the specific changes you would like to see? Thanks Jinrong Liang > > --- > .../selftests/kvm/include/ucall_common.h | 19 ++++++++--------- > tools/testing/selftests/kvm/lib/assert.c | 13 +++++++----- > .../testing/selftests/kvm/lib/ucall_common.c | 21 +++++++++++++++++++ > 3 files changed, 38 insertions(+), 15 deletions(-) > > diff --git a/tools/testing/selftests/kvm/include/ucall_common.h b/tools/testing/selftests/kvm/include/ucall_common.h > index b4f4c88e8d84..3bc4e62bec1b 100644 > --- a/tools/testing/selftests/kvm/include/ucall_common.h > +++ b/tools/testing/selftests/kvm/include/ucall_common.h > @@ -25,6 +25,7 @@ struct ucall { > uint64_t cmd; > uint64_t args[UCALL_MAX_ARGS]; > char buffer[UCALL_BUFFER_LEN]; > + char aux_buffer[UCALL_BUFFER_LEN]; > > /* Host virtual address of this struct. */ > struct ucall *hva; > @@ -36,6 +37,8 @@ void *ucall_arch_get_ucall(struct kvm_vcpu *vcpu); > > void ucall(uint64_t cmd, int nargs, ...); > void ucall_fmt(uint64_t cmd, const char *fmt, ...); > +void ucall_assert(uint64_t cmd, const char *exp, const char *file, > + unsigned int line, const char *fmt, ...); > uint64_t get_ucall(struct kvm_vcpu *vcpu, struct ucall *uc); > void ucall_init(struct kvm_vm *vm, vm_paddr_t mmio_gpa); > int ucall_nr_pages_required(uint64_t page_size); > @@ -63,15 +66,10 @@ enum guest_assert_builtin_args { > GUEST_ASSERT_BUILTIN_NARGS > }; > > -#define __GUEST_ASSERT_FMT(_condition, _str, _fmt, _args...) \ > -do { \ > - char fmt[UCALL_BUFFER_LEN]; \ > - \ > - if (!(_condition)) { \ > - guest_snprintf(fmt, sizeof(fmt), "%s\n %s", \ > - "Failed guest assert: " _str " at %s:%ld", _fmt); \ > - ucall_fmt(UCALL_ABORT, fmt, __FILE__, __LINE__, ##_args); \ > - } \ > +#define __GUEST_ASSERT_FMT(_condition, _str, _fmt, _args...) \ > +do { \ > + if (!(_condition)) \ > + ucall_assert(UCALL_ABORT, _str, __FILE__, __LINE__, _fmt, ##_args); \ > } while (0) > > #define GUEST_ASSERT_FMT(_condition, _fmt, _args...) \ > @@ -102,7 +100,8 @@ do { \ > > #define GUEST_ASSERT_EQ(a, b) __GUEST_ASSERT((a) == (b), #a " == " #b, 2, a, b) > > -#define REPORT_GUEST_ASSERT_FMT(_ucall) TEST_FAIL("%s", _ucall.buffer) > +#define REPORT_GUEST_ASSERT_FMT(ucall) \ > + test_assert(false, (ucall).aux_buffer, NULL, 0, "%s", (ucall).buffer); > > #define __REPORT_GUEST_ASSERT(_ucall, fmt, _args...) \ > TEST_FAIL("%s at %s:%ld\n" fmt, \ > diff --git a/tools/testing/selftests/kvm/lib/assert.c b/tools/testing/selftests/kvm/lib/assert.c > index 2bd25b191d15..74d94a34cf1a 100644 > --- a/tools/testing/selftests/kvm/lib/assert.c > +++ b/tools/testing/selftests/kvm/lib/assert.c > @@ -75,11 +75,14 @@ test_assert(bool exp, const char *exp_str, > if (!(exp)) { > va_start(ap, fmt); > > - fprintf(stderr, "==== Test Assertion Failure ====\n" > - " %s:%u: %s\n" > - " pid=%d tid=%d errno=%d - %s\n", > - file, line, exp_str, getpid(), _gettid(), > - errno, strerror(errno)); > + fprintf(stderr, "==== Test Assertion Failure ====\n"); > + /* If @file is NULL, @exp_str contains a preformatted string. */ > + if (file) > + fprintf(stderr, " %s:%u: %s\n", file, line, exp_str); > + else > + fprintf(stderr, " %s\n", exp_str); > + fprintf(stderr, " pid=%d tid=%d errno=%d - %s\n", > + getpid(), _gettid(), errno, strerror(errno)); > test_dump_stack(); > if (fmt) { > fputs(" ", stderr); > diff --git a/tools/testing/selftests/kvm/lib/ucall_common.c b/tools/testing/selftests/kvm/lib/ucall_common.c > index b507db91139b..e7741aadf2ce 100644 > --- a/tools/testing/selftests/kvm/lib/ucall_common.c > +++ b/tools/testing/selftests/kvm/lib/ucall_common.c > @@ -75,6 +75,27 @@ static void ucall_free(struct ucall *uc) > clear_bit(uc - ucall_pool->ucalls, ucall_pool->in_use); > } > > +void ucall_assert(uint64_t cmd, const char *exp, const char *file, > + unsigned int line, const char *fmt, ...) > +{ > + struct ucall *uc; > + va_list va; > + > + uc = ucall_alloc(); > + uc->cmd = cmd; > + > + guest_snprintf(uc->aux_buffer, sizeof(uc->aux_buffer), > + "%s:%u: %s", file, line, exp); > + > + va_start(va, fmt); > + guest_vsnprintf(uc->buffer, UCALL_BUFFER_LEN, fmt, va); > + va_end(va); > + > + ucall_arch_do_ucall((vm_vaddr_t)uc->hva); > + > + ucall_free(uc); > +} > + > void ucall_fmt(uint64_t cmd, const char *fmt, ...) > { > struct ucall *uc; > > base-commit: 8dc29dfc010293957c5ca24271748a3c8f047a76
> > The easiest thing I can think of is to add a second buffer to hold the exp+file+line. > Then, test_assert() just needs to skip that particular line of formatting. > > If you don't object, I'll post a v4 with the below folded in somewhere (after > more testing), and put this on the fast track for 6.6. > Yes, please update in v4. That should cause less confusion when reading the assert. I like it! > Side topic, if anyone lurking out there wants an easy (but tedious and boring) > starter project, we should convert all tests to the newfangled formatting and > drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() > and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. >
On Thu, Jul 27, 2023, Aaron Lewis wrote: > > > > The easiest thing I can think of is to add a second buffer to hold the exp+file+line. > > Then, test_assert() just needs to skip that particular line of formatting. Gah, had a brain fart. There's no need to format the expression+file+line in the guest, we can pass pointers to the expression and file, just like we already do for the existing guest asserts. v4 coming soon...
On Thu, Jul 27, 2023, JinrongLiang wrote: > > 在 2023/7/27 06:41, Sean Christopherson 写道: > > Side topic, if anyone lurking out there wants an easy (but tedious and boring) > > starter project, we should convert all tests to the newfangled formatting and > > drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() > > and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. > > I'd be happy to get the job done. > > However, before I proceed, could you please provide a more detailed example > or further guidance on the desired formatting and the specific changes you > would like to see? Hrm, scratch that request. I was thinking we could convert tests one-by-one, but that won't work well because to do a one-by-one conversions, tests that use GUEST_ASSERT_EQ() would need to first convert to e.g. GUEST_ASSERT_EQ_FMT() and then convert back, which would be a silly amount of churn just to a void a single selftests-wide patch. It probably makes sense to just convert everything as part of this series. There are quite a few asserts that need a message, but not *that* many.
On Thu, Jul 27, 2023, Sean Christopherson wrote: > On Thu, Jul 27, 2023, JinrongLiang wrote: > > > > 在 2023/7/27 06:41, Sean Christopherson 写道: > > > Side topic, if anyone lurking out there wants an easy (but tedious and boring) > > > starter project, we should convert all tests to the newfangled formatting and > > > drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() > > > and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. > > > > I'd be happy to get the job done. > > > > However, before I proceed, could you please provide a more detailed example > > or further guidance on the desired formatting and the specific changes you > > would like to see? > > Hrm, scratch that request. I was thinking we could convert tests one-by-one, but > that won't work well because to do a one-by-one conversions, tests that use > GUEST_ASSERT_EQ() would need to first convert to e.g. GUEST_ASSERT_EQ_FMT() and > then convert back, which would be a silly amount of churn just to a void a single > selftests-wide patch. > > It probably makes sense to just convert everything as part of this series. There > are quite a few asserts that need a message, but not *that* many. Aha! And there's already a "tree"-wide patch in this area to rename ASSERT_EQ() to TEST_ASSERT_EQ()[*]. I'll include that in v4 as well, and then piggyback on it to implement the new and improved GUEST_ASSERT_EQ(). [*] https://lore.kernel.org/all/20230712075910.22480-2-thuth@redhat.com
Sean Christopherson <seanjc@google.com> 于2023年7月28日周五 03:21写道： > > On Thu, Jul 27, 2023, Sean Christopherson wrote: > > On Thu, Jul 27, 2023, JinrongLiang wrote: > > > > > > 在 2023/7/27 06:41, Sean Christopherson 写道: > > > > Side topic, if anyone lurking out there wants an easy (but tedious and boring) > > > > starter project, we should convert all tests to the newfangled formatting and > > > > drop GUEST_ASSERT_N entirely. Once all tests are converted, GUEST_ASSERT_FMT() > > > > and REPORT_GUEST_ASSERT_FMT can drop the "FMT" postfix. > > > > > > I'd be happy to get the job done. > > > > > > However, before I proceed, could you please provide a more detailed example > > > or further guidance on the desired formatting and the specific changes you > > > would like to see? > > > > Hrm, scratch that request. I was thinking we could convert tests one-by-one, but > > that won't work well because to do a one-by-one conversions, tests that use > > GUEST_ASSERT_EQ() would need to first convert to e.g. GUEST_ASSERT_EQ_FMT() and > > then convert back, which would be a silly amount of churn just to a void a single > > selftests-wide patch. > > > > It probably makes sense to just convert everything as part of this series. There > > are quite a few asserts that need a message, but not *that* many. > > Aha! And there's already a "tree"-wide patch in this area to rename ASSERT_EQ() > to TEST_ASSERT_EQ()[*]. I'll include that in v4 as well, and then piggyback on it > to implement the new and improved GUEST_ASSERT_EQ(). > > [*] https://lore.kernel.org/all/20230712075910.22480-2-thuth@redhat.com Thank you for your response and suggestions. I believe your recommendation is an excellent approach. Please let me know if there's anything else I can help with or any specific tasks you'd like me to work on. I appreciate your guidance and the opportunity to contribute to KVM.