[U-Boot] [PATCH 4/4] efi_loader: indent entry/exit prints to show nesting level

Alexander Graf
2017-07-28T10:22:24Z

On 28.07.17 12:11, Rob Clark wrote:
> On Fri, Jul 28, 2017 at 5:36 AM, Alexander Graf <agraf@suse.de> wrote:
>>
>>
>> On 28.07.17 11:34, Rob Clark wrote:
>>>
>>> On Fri, Jul 28, 2017 at 5:25 AM, Alexander Graf <agraf@suse.de> wrote:
>>>>
>>>>
>>>>
>>>> On 28.07.17 11:19, Rob Clark wrote:
>>>>>
>>>>>
>>>>> On Fri, Jul 28, 2017 at 3:24 AM, Alexander Graf <agraf@suse.de> wrote:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On 27.07.17 14:04, Rob Clark wrote:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> This should make it easier to see when a callback back to UEFI world
>>>>>>> calls back in to the u-boot world, and generally match up EFI_ENTRY()
>>>>>>> and EFI_EXIT() calls.
>>>>>>>
>>>>>>> Signed-off-by: Rob Clark <robdclark@gmail.com>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> Doesn't the previous patch ensure that we're always only going 1 level
>>>>>> deep?
>>>>>
>>>>>
>>>>>
>>>>> two separate counters for nesting and entry level. We can be more
>>>>> deeply nested when EFI_CALL() is used :-)
>>>>
>>>>
>>>>
>>>> Ah, so this basically gives you the EFI_CALL nesting level? Wouldn't it
>>>> make
>>>> sense to also increase the nesting level on every application invocation?
>>>
>>>
>>> I specifically avoided that since (at least at what I was looking at)
>>> each successive application invocation never returns.
>>>
>>> Maybe instead we should just do something like:
>>> debug("========================================\n") to show the
>>> application invocation boundaries more easily?
>>
>>
>> Sounds like a good idea to me :). Ideally with a bit more information such
>> as the file path.
>>
>
> well, until my RFC patchset, there is no guarantee to be a file path ;-)
>
> And both the device and file path will be efi_device_path. I have
> some thoughts to spiff out device_path_to_text a bit more to make it
> more complete and also suitable for internal debugging use.. but that
> is going to be post-MW. Once that happens we can add some more
> information, but for now the boring "===========" is all we can do.

No worries, we can introduce a fancy ========= when the time is ripe :).

>
>>
>>>
>>>>
>>>>>
>>>>>>
>>>>>>> ---
>>>>>>> include/efi_loader.h | 12 ++++++++----
>>>>>>> lib/efi_loader/efi_boottime.c | 25 +++++++++++++++++++++++++
>>>>>>> 2 files changed, 33 insertions(+), 4 deletions(-)
>>>>>>>
>>>>>>> diff --git a/include/efi_loader.h b/include/efi_loader.h
>>>>>>> index 4262d0ac6b..037cc7c543 100644
>>>>>>> --- a/include/efi_loader.h
>>>>>>> +++ b/include/efi_loader.h
>>>>>>> @@ -17,13 +17,16 @@
>>>>>>> int __efi_entry_check(void);
>>>>>>> int __efi_exit_check(void);
>>>>>>> +const char *__efi_nesting_inc(void);
>>>>>>> +const char *__efi_nesting_dec(void);
>>>>>>> /*
>>>>>>> * Enter the u-boot world from UEFI:
>>>>>>> */
>>>>>>> #define EFI_ENTRY(format, ...) do { \
>>>>>>> assert(__efi_entry_check()); \
>>>>>>> - debug("EFI: Entry %s(" format ")\n", __func__, ##__VA_ARGS__);
>>>>>>> \
>>>>>>> + debug("%sEFI: Entry %s(" format ")\n", __efi_nesting_inc(), \
>>>>>>> + __func__, ##__VA_ARGS__); \
>>>>>>> } while(0)
>>>>>>> /*
>>>>>>> @@ -31,7 +34,8 @@ int __efi_exit_check(void);
>>>>>>> */
>>>>>>> #define EFI_EXIT(ret) ({ \
>>>>>>> efi_status_t _r = ret; \
>>>>>>> - debug("EFI: Exit: %s: %u\n", __func__, (u32)(_r &
>>>>>>> ~EFI_ERROR_MASK)); \
>>>>>>> + debug("%sEFI: Exit: %s: %u\n", __efi_nesting_dec(), \
>>>>>>> + __func__, (u32)(_r & ~EFI_ERROR_MASK)); \
>>>>>>> assert(__efi_exit_check()); \
>>>>>>> _r; \
>>>>>>> })
>>>>>>> @@ -40,11 +44,11 @@ int __efi_exit_check(void);
>>>>>>> * Callback into UEFI world from u-boot:
>>>>>>> */
>>>>>>> #define EFI_CALL(exp) do { \
>>>>>>> - debug("EFI: Call: %s\n", #exp); \
>>>>>>> + debug("%sEFI: Call: %s\n", __efi_nesting_inc(), #exp); \
>>>>>>> assert(__efi_exit_check()); \
>>>>>>> exp; \
>>>>>>> assert(__efi_entry_check()); \
>>>>>>> - debug("EFI: Return From: %s\n", #exp); \
>>>>>>> + debug("%sEFI: Return From: %s\n", __efi_nesting_dec(), #exp);
>>>>>>> \
>>>>>>> } while(0)
>>>>>>> extern struct efi_runtime_services efi_runtime_services;
>>>>>>> diff --git a/lib/efi_loader/efi_boottime.c
>>>>>>> b/lib/efi_loader/efi_boottime.c
>>>>>>> index 66137d4ff9..de338f009c 100644
>>>>>>> --- a/lib/efi_loader/efi_boottime.c
>>>>>>> +++ b/lib/efi_loader/efi_boottime.c
>>>>>>> @@ -50,6 +50,7 @@ static volatile void *efi_gd, *app_gd;
>>>>>>> #endif
>>>>>>> static int entry_count;
>>>>>>> +static int nesting_level;
>>>>>>> /* Called on every callback entry */
>>>>>>> int __efi_entry_check(void)
>>>>>>> @@ -96,6 +97,28 @@ void efi_restore_gd(void)
>>>>>>> #endif
>>>>>>> }
>>>>>>> +/*
>>>>>>> + * Two spaces per indent level, maxing out at 10.. which ought to be
>>>>>>> + * enough for anyone ;-)
>>>>>>> + */
>>>>>>> +static const char *indent_string(int level)
>>>>>>> +{
>>>>>>> + static const char *indent = " ";
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> There's no need for this to be static, no?
>>>>>
>>>>>
>>>>>
>>>>> I suppose it doesn't *need* to be.. but it also doesn't need to have
>>>>> scope outside the file, and usually static is a good hint to the
>>>>> compiler to inline it. (If non-static the compiler needs to emit a
>>>>> non-inlined version of it since it doesn't know it won't be called
>>>>> outside of this object file.
>>>>
>>>>
>>>>
>>>> I don't mean the function, I mean the indent. If you do
>>>>
>>>> static const char *indent = <const value>;
>>>>
>>>> it should be practically the same as
>>>>
>>>> const char *indent = <const value>;
>>>>
>>>> no?
>>>
>>>
>>> hmm, I didn't want the compiler to instantiate the array on the stack.
>>> But I suppose I need to check the generated asm to see how clever it
>>> is.
>>
>>
>> It really shouldn't do that. As long as you're just juggling pointers to a
>> region in .rodata it should know exactly what's going on.
>>
>
> I'll double check when I get to the office.. making it static doesn't
> hurt and forces the compiler to do what we want (.rodata). Without
> the 'static' it might end up doing the same thing.

Well, every time i see a "static" declared variable inside a function
scope my alarm bells ring :). So I'd prefer we had as few as possible.

In fact, I *think* what your line does is it puts the pointer into a
global in .data which really isn't what we want.

Alex