| Message ID | 20220203133829.7913-1-andrew.cooper3@citrix.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | xen: Modify domain_crash() to take a print string | expand |
Hi, On 03/02/2022 13:38, Andrew Cooper wrote: > diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h > index 37f78cc4c4c9..38b390d20371 100644 > --- a/xen/include/xen/sched.h > +++ b/xen/include/xen/sched.h > @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); > * from any processor. > */ > void __domain_crash(struct domain *d); > -#define domain_crash(d) do { \ > - printk("domain_crash called from %s:%d\n", __FILE__, __LINE__); \ > - __domain_crash(d); \ > -} while (0) > +#define domain_crash(d, ...) \ > + do { \ > + if ( count_args(__VA_ARGS__) == 0 ) \ > + printk("domain_crash called from %s:%d\n", \ > + __FILE__, __LINE__); \ I find a bit odd that here you are using a normal printk but... > + else \ > + printk(XENLOG_G_ERR __VA_ARGS__); \ here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, wouldn't it be better to only use XENLOG_ERR so they can always be seen? (A domain shouldn't be able to abuse it). Cheers,
On 03/02/2022 13:48, Julien Grall wrote: > Hi, > > On 03/02/2022 13:38, Andrew Cooper wrote: >> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >> index 37f78cc4c4c9..38b390d20371 100644 >> --- a/xen/include/xen/sched.h >> +++ b/xen/include/xen/sched.h >> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >> * from any processor. >> */ >> void __domain_crash(struct domain *d); >> -#define domain_crash(d) do >> { \ >> - printk("domain_crash called from %s:%d\n", __FILE__, >> __LINE__); \ >> - >> __domain_crash(d); \ >> -} while (0) >> +#define domain_crash(d, ...) \ >> + do { \ >> + if ( count_args(__VA_ARGS__) == 0 ) \ >> + printk("domain_crash called from %s:%d\n", \ >> + __FILE__, __LINE__); \ > > I find a bit odd that here you are using a normal printk That's unmodified from before. Only reformatted. > but... > > >> + else \ >> + printk(XENLOG_G_ERR __VA_ARGS__); \ > > here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, > wouldn't it be better to only use XENLOG_ERR so they can always be > seen? (A domain shouldn't be able to abuse it). Perhaps. I suppose it is more important information than pretty much anything else about the guest. I've changed locally, but won't repost just for this. ~Andrew
Hi Andrew, On 03/02/2022 14:11, Andrew Cooper wrote: > On 03/02/2022 13:48, Julien Grall wrote: >> Hi, >> >> On 03/02/2022 13:38, Andrew Cooper wrote: >>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>> index 37f78cc4c4c9..38b390d20371 100644 >>> --- a/xen/include/xen/sched.h >>> +++ b/xen/include/xen/sched.h >>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>> * from any processor. >>> */ >>> void __domain_crash(struct domain *d); >>> -#define domain_crash(d) do >>> { \ >>> - printk("domain_crash called from %s:%d\n", __FILE__, >>> __LINE__); \ >>> - >>> __domain_crash(d); \ >>> -} while (0) >>> +#define domain_crash(d, ...) \ >>> + do { \ >>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>> + printk("domain_crash called from %s:%d\n", \ >>> + __FILE__, __LINE__); \ >> >> I find a bit odd that here you are using a normal printk > > That's unmodified from before. Only reformatted. > >> but... >> >> >>> + else \ >>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >> >> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >> wouldn't it be better to only use XENLOG_ERR so they can always be >> seen? (A domain shouldn't be able to abuse it). > > Perhaps. I suppose it is more important information than pretty much > anything else about the guest. > > I've changed locally, but won't repost just for this. Ok. With that: Reviewed-by: Julien Grall <jgrall@amazon.com> Cheers,
On 03.02.2022 15:11, Andrew Cooper wrote: > On 03/02/2022 13:48, Julien Grall wrote: >> On 03/02/2022 13:38, Andrew Cooper wrote: >>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>> index 37f78cc4c4c9..38b390d20371 100644 >>> --- a/xen/include/xen/sched.h >>> +++ b/xen/include/xen/sched.h >>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>> * from any processor. >>> */ >>> void __domain_crash(struct domain *d); >>> -#define domain_crash(d) do >>> { \ >>> - printk("domain_crash called from %s:%d\n", __FILE__, >>> __LINE__); \ >>> - >>> __domain_crash(d); \ >>> -} while (0) >>> +#define domain_crash(d, ...) \ >>> + do { \ >>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>> + printk("domain_crash called from %s:%d\n", \ >>> + __FILE__, __LINE__); \ >> >> I find a bit odd that here you are using a normal printk > > That's unmodified from before. Only reformatted. > >> but... >> >> >>> + else \ >>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >> >> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >> wouldn't it be better to only use XENLOG_ERR so they can always be >> seen? (A domain shouldn't be able to abuse it). > > Perhaps. I suppose it is more important information than pretty much > anything else about the guest. Indeed, but then - is this really an error in all cases? The prior printk() simply ended up defaulting to a warning, and I would think that's what the new one should be doing too. Or even leave the setting of the log level to the invocation sites of the macro. Jan
On 03/02/2022 14:19, Jan Beulich wrote: > On 03.02.2022 15:11, Andrew Cooper wrote: >> On 03/02/2022 13:48, Julien Grall wrote: >>> On 03/02/2022 13:38, Andrew Cooper wrote: >>>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>>> index 37f78cc4c4c9..38b390d20371 100644 >>>> --- a/xen/include/xen/sched.h >>>> +++ b/xen/include/xen/sched.h >>>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>>> * from any processor. >>>> */ >>>> void __domain_crash(struct domain *d); >>>> -#define domain_crash(d) do >>>> { \ >>>> - printk("domain_crash called from %s:%d\n", __FILE__, >>>> __LINE__); \ >>>> - >>>> __domain_crash(d); \ >>>> -} while (0) >>>> +#define domain_crash(d, ...) \ >>>> + do { \ >>>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>>> + printk("domain_crash called from %s:%d\n", \ >>>> + __FILE__, __LINE__); \ >>> I find a bit odd that here you are using a normal printk >> That's unmodified from before. Only reformatted. >> >>> but... >>> >>> >>>> + else \ >>>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >>> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >>> wouldn't it be better to only use XENLOG_ERR so they can always be >>> seen? (A domain shouldn't be able to abuse it). >> Perhaps. I suppose it is more important information than pretty much >> anything else about the guest. > Indeed, but then - is this really an error in all cases? Yes. It is always a fatal event for the VM. > The prior > printk() simply ended up defaulting to a warning, and I would think > that's what the new one should be doing too. WARNING isn't exactly correct for a fatal event. Ideally, we want a non-ratelimited G_ERR, but that doesn't exist. If it appears in the future, we can use it. The set of people running with loglvl=error is almost certainly empty, so it doesn't matter. ~Andrew
On 03.02.2022 15:41, Andrew Cooper wrote: > On 03/02/2022 14:19, Jan Beulich wrote: >> On 03.02.2022 15:11, Andrew Cooper wrote: >>> On 03/02/2022 13:48, Julien Grall wrote: >>>> On 03/02/2022 13:38, Andrew Cooper wrote: >>>>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>>>> index 37f78cc4c4c9..38b390d20371 100644 >>>>> --- a/xen/include/xen/sched.h >>>>> +++ b/xen/include/xen/sched.h >>>>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>>>> * from any processor. >>>>> */ >>>>> void __domain_crash(struct domain *d); >>>>> -#define domain_crash(d) do >>>>> { \ >>>>> - printk("domain_crash called from %s:%d\n", __FILE__, >>>>> __LINE__); \ >>>>> - >>>>> __domain_crash(d); \ >>>>> -} while (0) >>>>> +#define domain_crash(d, ...) \ >>>>> + do { \ >>>>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>>>> + printk("domain_crash called from %s:%d\n", \ >>>>> + __FILE__, __LINE__); \ >>>> I find a bit odd that here you are using a normal printk >>> That's unmodified from before. Only reformatted. >>> >>>> but... >>>> >>>> >>>>> + else \ >>>>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >>>> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >>>> wouldn't it be better to only use XENLOG_ERR so they can always be >>>> seen? (A domain shouldn't be able to abuse it). >>> Perhaps. I suppose it is more important information than pretty much >>> anything else about the guest. >> Indeed, but then - is this really an error in all cases? > > Yes. It is always a fatal event for the VM. Which may or may not be Xen's fault. If the guest put itself in a bad state, I don't see why we shouldn't consider such just a warning. IOW I continue to think a log level, if so wanted, should be supplied by the user of the macro. Jan
On 03/02/2022 15:06, Jan Beulich wrote: > On 03.02.2022 15:41, Andrew Cooper wrote: >> On 03/02/2022 14:19, Jan Beulich wrote: >>> On 03.02.2022 15:11, Andrew Cooper wrote: >>>> On 03/02/2022 13:48, Julien Grall wrote: >>>>> On 03/02/2022 13:38, Andrew Cooper wrote: >>>>>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>>>>> index 37f78cc4c4c9..38b390d20371 100644 >>>>>> --- a/xen/include/xen/sched.h >>>>>> +++ b/xen/include/xen/sched.h >>>>>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>>>>> * from any processor. >>>>>> */ >>>>>> void __domain_crash(struct domain *d); >>>>>> -#define domain_crash(d) do >>>>>> { \ >>>>>> - printk("domain_crash called from %s:%d\n", __FILE__, >>>>>> __LINE__); \ >>>>>> - >>>>>> __domain_crash(d); \ >>>>>> -} while (0) >>>>>> +#define domain_crash(d, ...) \ >>>>>> + do { \ >>>>>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>>>>> + printk("domain_crash called from %s:%d\n", \ >>>>>> + __FILE__, __LINE__); \ >>>>> I find a bit odd that here you are using a normal printk >>>> That's unmodified from before. Only reformatted. >>>> >>>>> but... >>>>> >>>>> >>>>>> + else \ >>>>>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >>>>> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >>>>> wouldn't it be better to only use XENLOG_ERR so they can always be >>>>> seen? (A domain shouldn't be able to abuse it). >>>> Perhaps. I suppose it is more important information than pretty much >>>> anything else about the guest. >>> Indeed, but then - is this really an error in all cases? >> Yes. It is always a fatal event for the VM. > Which may or may not be Xen's fault. If the guest put itself in a bad > state, I don't see why we shouldn't consider such just a warning. Log level is the severity of the action, not who's potentially to blame for causing the situation. Furthermore, almost all callers who do emit appropriate diagnostics before domain_crash() already use ERR. And, as already pointed out, it doesn't matter. The line is going out on the console however you want to try and bikeshed the internals. > IOW > I continue to think a log level, if so wanted, should be supplied by > the user of the macro. That undermines the whole purpose of preventing callers from being able to omit diagnostics. ~Andrew
On 03.02.2022 14:38, Andrew Cooper wrote: > --- a/xen/arch/x86/domain.c > +++ b/xen/arch/x86/domain.c > @@ -1693,11 +1693,8 @@ static void load_segments(struct vcpu *n) > put_guest(uregs->fs, esp - 5) | > put_guest(uregs->es, esp - 6) | > put_guest(uregs->ds, esp - 7) ) > - { > - gprintk(XENLOG_ERR, > - "error while creating compat failsafe callback frame\n"); > - domain_crash(n->domain); > - } > + domain_crash(n->domain, > + "Error creating compat failsafe callback frame\n"); > > if ( n->arch.pv.vgc_flags & VGCF_failsafe_disables_events ) > vcpu_info(n, evtchn_upcall_mask) = 1; > @@ -1732,11 +1729,8 @@ static void load_segments(struct vcpu *n) > put_guest(uregs->ds, rsp - 9) | > put_guest(regs->r11, rsp - 10) | > put_guest(regs->rcx, rsp - 11) ) > - { > - gprintk(XENLOG_ERR, > - "error while creating failsafe callback frame\n"); > - domain_crash(n->domain); > - } > + domain_crash(n->domain, > + "Error creating failsafe callback frame\n"); I assume it wasn't really intended to hide potentially relevant information (the subject vCPU) by this change, which - by way of gprintk() - did get logged before (since we already have n == current at this point)? Jan
On 04.02.2022 12:56, Andrew Cooper wrote: > On 03/02/2022 15:06, Jan Beulich wrote: >> On 03.02.2022 15:41, Andrew Cooper wrote: >>> On 03/02/2022 14:19, Jan Beulich wrote: >>>> On 03.02.2022 15:11, Andrew Cooper wrote: >>>>> On 03/02/2022 13:48, Julien Grall wrote: >>>>>> On 03/02/2022 13:38, Andrew Cooper wrote: >>>>>>> diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h >>>>>>> index 37f78cc4c4c9..38b390d20371 100644 >>>>>>> --- a/xen/include/xen/sched.h >>>>>>> +++ b/xen/include/xen/sched.h >>>>>>> @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); >>>>>>> * from any processor. >>>>>>> */ >>>>>>> void __domain_crash(struct domain *d); >>>>>>> -#define domain_crash(d) do >>>>>>> { \ >>>>>>> - printk("domain_crash called from %s:%d\n", __FILE__, >>>>>>> __LINE__); \ >>>>>>> - >>>>>>> __domain_crash(d); \ >>>>>>> -} while (0) >>>>>>> +#define domain_crash(d, ...) \ >>>>>>> + do { \ >>>>>>> + if ( count_args(__VA_ARGS__) == 0 ) \ >>>>>>> + printk("domain_crash called from %s:%d\n", \ >>>>>>> + __FILE__, __LINE__); \ >>>>>> I find a bit odd that here you are using a normal printk >>>>> That's unmodified from before. Only reformatted. >>>>> >>>>>> but... >>>>>> >>>>>> >>>>>>> + else \ >>>>>>> + printk(XENLOG_G_ERR __VA_ARGS__); \ >>>>>> here it is XENLOG_G_ERR. In fact, isn't it ratelimited? If so, >>>>>> wouldn't it be better to only use XENLOG_ERR so they can always be >>>>>> seen? (A domain shouldn't be able to abuse it). >>>>> Perhaps. I suppose it is more important information than pretty much >>>>> anything else about the guest. >>>> Indeed, but then - is this really an error in all cases? >>> Yes. It is always a fatal event for the VM. >> Which may or may not be Xen's fault. If the guest put itself in a bad >> state, I don't see why we shouldn't consider such just a warning. > > Log level is the severity of the action, not who's potentially to blame > for causing the situation. > > Furthermore, almost all callers who do emit appropriate diagnostics > before domain_crash() already use ERR. Well, yes, this looks to indeed be the case (albeit frequently with gdprintk(), in which case I'm inclined to say the log level isn't very relevant in the first place). On this basis I'm willing to give in, despite continuing to not being fully convinced. Jan
On 04/02/2022 12:54 pm, Jan Beulich wrote: > On 03.02.2022 14:38, Andrew Cooper wrote: >> --- a/xen/arch/x86/domain.c >> +++ b/xen/arch/x86/domain.c >> @@ -1693,11 +1693,8 @@ static void load_segments(struct vcpu *n) >> put_guest(uregs->fs, esp - 5) | >> put_guest(uregs->es, esp - 6) | >> put_guest(uregs->ds, esp - 7) ) >> - { >> - gprintk(XENLOG_ERR, >> - "error while creating compat failsafe >> callback frame\n"); >> - domain_crash(n->domain); >> - } >> + domain_crash(n->domain, >> + "Error creating compat failsafe >> callback frame\n"); >> >> if ( n->arch.pv.vgc_flags & VGCF_failsafe_disables_events ) >> vcpu_info(n, evtchn_upcall_mask) = 1; >> @@ -1732,11 +1729,8 @@ static void load_segments(struct vcpu *n) >> put_guest(uregs->ds, rsp - 9) | >> put_guest(regs->r11, rsp - 10) | >> put_guest(regs->rcx, rsp - 11) ) >> - { >> - gprintk(XENLOG_ERR, >> - "error while creating failsafe callback frame\n"); >> - domain_crash(n->domain); >> - } >> + domain_crash(n->domain, >> + "Error creating failsafe callback frame\n"); > > I assume it wasn't really intended to hide potentially relevant > information > (the subject vCPU) by this change, which - by way of gprintk() - did get > logged before (since we already have n == current at this point)? The information is not lost. __domain_crash() prints current too, albeit in a long-winded way. ~Andrew
On 24.03.2023 00:15, Andrew Cooper wrote: > On 04/02/2022 12:54 pm, Jan Beulich wrote: >> On 03.02.2022 14:38, Andrew Cooper wrote: >>> --- a/xen/arch/x86/domain.c >>> +++ b/xen/arch/x86/domain.c >>> @@ -1693,11 +1693,8 @@ static void load_segments(struct vcpu *n) >>> put_guest(uregs->fs, esp - 5) | >>> put_guest(uregs->es, esp - 6) | >>> put_guest(uregs->ds, esp - 7) ) >>> - { >>> - gprintk(XENLOG_ERR, >>> - "error while creating compat failsafe >>> callback frame\n"); >>> - domain_crash(n->domain); >>> - } >>> + domain_crash(n->domain, >>> + "Error creating compat failsafe >>> callback frame\n"); >>> >>> if ( n->arch.pv.vgc_flags & VGCF_failsafe_disables_events ) >>> vcpu_info(n, evtchn_upcall_mask) = 1; >>> @@ -1732,11 +1729,8 @@ static void load_segments(struct vcpu *n) >>> put_guest(uregs->ds, rsp - 9) | >>> put_guest(regs->r11, rsp - 10) | >>> put_guest(regs->rcx, rsp - 11) ) >>> - { >>> - gprintk(XENLOG_ERR, >>> - "error while creating failsafe callback frame\n"); >>> - domain_crash(n->domain); >>> - } >>> + domain_crash(n->domain, >>> + "Error creating failsafe callback frame\n"); >> >> I assume it wasn't really intended to hide potentially relevant >> information >> (the subject vCPU) by this change, which - by way of gprintk() - did get >> logged before (since we already have n == current at this point)? > > The information is not lost. __domain_crash() prints current too, > albeit in a long-winded way. Oh, right - n == current guarantees the middle path to be taken there. Considering the other sub-thread also ended up okay-ish: Reviewed-by: Jan Beulich <jbeulich@suse.com> Jan
diff --git a/xen/arch/x86/domain.c b/xen/arch/x86/domain.c index ef1812dc1402..45be5e1cd7c9 100644 --- a/xen/arch/x86/domain.c +++ b/xen/arch/x86/domain.c @@ -1693,11 +1693,8 @@ static void load_segments(struct vcpu *n) put_guest(uregs->fs, esp - 5) | put_guest(uregs->es, esp - 6) | put_guest(uregs->ds, esp - 7) ) - { - gprintk(XENLOG_ERR, - "error while creating compat failsafe callback frame\n"); - domain_crash(n->domain); - } + domain_crash(n->domain, + "Error creating compat failsafe callback frame\n"); if ( n->arch.pv.vgc_flags & VGCF_failsafe_disables_events ) vcpu_info(n, evtchn_upcall_mask) = 1; @@ -1732,11 +1729,8 @@ static void load_segments(struct vcpu *n) put_guest(uregs->ds, rsp - 9) | put_guest(regs->r11, rsp - 10) | put_guest(regs->rcx, rsp - 11) ) - { - gprintk(XENLOG_ERR, - "error while creating failsafe callback frame\n"); - domain_crash(n->domain); - } + domain_crash(n->domain, + "Error creating failsafe callback frame\n"); if ( n->arch.pv.vgc_flags & VGCF_failsafe_disables_events ) vcpu_info(n, evtchn_upcall_mask) = 1; diff --git a/xen/include/xen/sched.h b/xen/include/xen/sched.h index 37f78cc4c4c9..38b390d20371 100644 --- a/xen/include/xen/sched.h +++ b/xen/include/xen/sched.h @@ -736,10 +736,15 @@ void vcpu_end_shutdown_deferral(struct vcpu *v); * from any processor. */ void __domain_crash(struct domain *d); -#define domain_crash(d) do { \ - printk("domain_crash called from %s:%d\n", __FILE__, __LINE__); \ - __domain_crash(d); \ -} while (0) +#define domain_crash(d, ...) \ + do { \ + if ( count_args(__VA_ARGS__) == 0 ) \ + printk("domain_crash called from %s:%d\n", \ + __FILE__, __LINE__); \ + else \ + printk(XENLOG_G_ERR __VA_ARGS__); \ + __domain_crash(d); \ + } while ( 0 ) /* * Called from assembly code, with an optional address to help indicate why
There are two problems with domain_crash(). First, that it is frequently not preceded by a printk() at all, or that it is only preceded by a dprintk(). Either way, critical diagnostic is omitted for an event which is fatal to the guest. Second, the embedded __LINE__ is an issue for livepatching, creating unwanted churn in the binary diff. This is the final __LINE__ remaining in livepatching-relevant contexts. The end goal is to have domain_crash() require a print string which gets fed to printk(), making it far less easy to omit relevant diagnostic information. However, modifying all callers at once is far too big and complicated, so use some macro magic to tolerate the old API (no print string) in the short term. Adjust two callers in load_segments() to demonstrate the new API. Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com> --- CC: Jan Beulich <JBeulich@suse.com> CC: Roger Pau Monné <roger.pau@citrix.com> CC: Wei Liu <wl@xen.org> CC: Stefano Stabellini <sstabellini@kernel.org> CC: Julien Grall <julien@xen.org> CC: Volodymyr Babchuk <Volodymyr_Babchuk@epam.com> CC: Bertrand Marquis <bertrand.marquis@arm.com> Supersedes my previous attempt to update every caller in one go. In due course I'll split that mammoth patch up into a series. --- xen/arch/x86/domain.c | 14 ++++---------- xen/include/xen/sched.h | 13 +++++++++---- 2 files changed, 13 insertions(+), 14 deletions(-)