This is an archive of the discontinued LLVM Phabricator instance.

[lldb] Add log indicating which kind of data formatter
ClosedPublic

Authored by kastiglione on Jun 29 2023, 11:17 AM.

Details

Summary

The formatter logs include a function name, but these functions are mostly templates
and the template type parameter is not printed, which is useful context.

This change adds a new log which is printed upon entry of FormatManager::Get, which
shows the formatter context as either format, summary, or synthetic.

Diff Detail

Event Timeline

kastiglione created this revision.Jun 29 2023, 11:17 AM
Herald added a project: Restricted Project. · View Herald TranscriptJun 29 2023, 11:17 AM
kastiglione requested review of this revision.Jun 29 2023, 11:17 AM
Herald added a project: Restricted Project. · View Herald TranscriptJun 29 2023, 11:17 AM
augusto2112 accepted this revision.Jun 29 2023, 11:38 AM

I've bumped into this problem before, so really like this change. It's a bit sad that you'll only print the kind of data formatter once though, so someone reading the logs might have to jump back and forth to understand what kind of formatter they're dealing with. There's also __PRETTY_FUNCTION__, which shows the generic type parameters by default, but I think it's not a standard macro (although it's implemented by both clang and gcc). What do you think of having a macro like:

#ifndef __PRETTY_FUNCTION__
   #define __PRETTY_FUNCTION__ __FUNCTION__
#endif

And replacing __FUNCTION__ with __PRETTY_FUNCTION__?

This revision is now accepted and ready to land.Jun 29 2023, 11:38 AM
kastiglione added a comment.EditedJun 29 2023, 12:59 PM

I just gave __PRETTY_FUNCTION__ a test drive, and it's a bit verbose/noisy: For example:

[ImplSP lldb_private::FormatManager::Get(lldb_private::ValueObject &, lldb::DynamicValueType) [ImplSP = std::shared_ptr<lldb_private::SyntheticChildren>]] Begin synthetic lookup.

Here's an example of the formatter logs with my change. Note that these logs are output in "blocks", that is the first line is prefixed with two newlines (\n\n):

[Get] Begin summary lookup.
 [GetCached] Looking into cache for type Swift.Optional<main.Item>
 [GetCached] Cache search failed. Going normal route
 [Get] candidate match = Swift.Optional<main.Item> no-strip-pointers no-strip-reference no-strip-typedef
 [Get] candidate match = main.Item? no-strip-pointers no-strip-reference no-strip-typedef
 [Get] candidate match = Swift.Optional<main.Item> no-strip-pointers no-strip-reference no-strip-typedef
 [Get] candidate match = Swift.Optional<main.Item> no-strip-pointers no-strip-reference no-strip-typedef
 [Get] candidate match = main.Item? no-strip-pointers no-strip-reference no-strip-typedef
 [Get] candidate match = Swift.Optional<main.Item> no-strip-pointers no-strip-reference no-strip-typedef
 [Get] Trying to use category default
 [Get] Trying to use category llvm
 [Get] Trying to use category VectorTypes
 [Get] Trying to use category runtime-synthetics
 [Get] Trying to use category system
 [Get] nothing found - returning empty SP
 [GetCached] Caching 0x0 for type Swift.Optional<main.Item>
 [Get] Search failed. Giving language a chance.
 [Get] Language search success. Returning.


[Get] Begin synthetic lookup.
...

At the beginning of the lines, those names in square brackets are the __FUNCTION__ macro. If they were replaced with __PRETTY_FUNCTION__, I think it would be too noisy.

someone reading the logs might have to jump back and forth to understand what kind of formatter they're dealing with

I agree that this isn't ideal, As mentioned above, there are two newlines used to group and separate related log statements. This is why I put the new log at the top. Someone reading these logs can look at the first line in the block to know what kind of formatter is active. It's hard to strike a balance: if every line says the formatter kind, it's both convenient but also redundant/noisy.

In summary:

  • I think __PRETTY_FUNCTION__ is too noisy to be useful
  • If we want each log statement to include the formatter kind, I am ok with that (but personally I can work with having it be mentioned at the top of each block)

Personally I vote for the formatter kind on every line, so we don't need to jump around the logs when reading them, up to you though.

Include formatter kind ("format", "summary", "synthetic") to FormatManager logs

Restore static_cast<void *>() because of -Wformat-pedantic

I've bumped into this problem before, so really like this change. It's a bit sad that you'll only print the kind of data formatter once though, so someone reading the logs might have to jump back and forth to understand what kind of formatter they're dealing with. There's also __PRETTY_FUNCTION__, which shows the generic type parameters by default, but I think it's not a standard macro (although it's implemented by both clang and gcc). What do you think of having a macro like:

#ifndef __PRETTY_FUNCTION__
   #define __PRETTY_FUNCTION__ __FUNCTION__
#endif

FWIW that's exactly what LLVM_PRETTY_FUNCTION does. It's implemented as you would expect (and you described): https://github.com/llvm/llvm-project/blob/5e2f0947c586042083cc1643f2aac90f2492bacb/llvm/include/llvm/Support/Compiler.h#L497

JDevlieghere requested changes to this revision.Jun 30 2023, 11:05 AM

Our logging infrastructure already supports including the function name in the log message. That has always been the case for LLDB_LOG but LLDB_LOGF wasn't updated until 6099d519bb83 because the idea was that everyone would move to formatv-style logging LLDB_LOG but that never gained consensus.

This revision now requires changes to proceed.Jun 30 2023, 11:05 AM
JDevlieghere added a comment.EditedJun 30 2023, 11:06 AM

I'm fine with keeping the template argument, but we should remove the redundant FUNCTION argument from the log messages themselves

Remove FUNCTION from FormatManager logs

This revision is now accepted and ready to land.Jun 30 2023, 2:40 PM