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

[Alexander Graf]

On 28.07.17 12:11, Rob Clark wrote:
> 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.

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