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

[Rob Clark]

On Fri, Jul 28, 2017 at 5:36 AM, Alexander Graf <agraf at suse.de> wrote:
>
>
> On 28.07.17 11:34, Rob Clark wrote:
>>
>> On Fri, Jul 28, 2017 at 5:25 AM, Alexander Graf <agraf at suse.de> wrote:
>>>
>>>
>>>
>>> On 28.07.17 11:19, Rob Clark wrote:
>>>>
>>>>
>>>> On Fri, Jul 28, 2017 at 3:24 AM, Alexander Graf <agraf at 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 at 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.

>
>>
>>>
>>>>
>>>>>
>>>>>> ---
>>>>>>     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.

BR,
-R