Bug 160969 – WebKit should set a subsystem for os_log so it's easier to filter for WebKit log messages

• Component: Web Template Framework
• Status: RESOLVED FIXED

[Keith Rollin]

<rdar://problem/26068734>

With the Logging 2.0 os_log API, you can set a custom subsystem for your logs. This allows you to later filter logs and see just what your subsystem logged.

[Keith Rollin]

Created attachment 286797 [details]
Patch

[WebKit Commit Bot]

Attachment 286797 [details] did not pass style-queue:


ERROR: Source/WTF/wtf/Assertions.h:151:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:156:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:159:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:435:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:436:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:441:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:442:  Extra space after ( in function call  [whitespace/parens] [4]
Total errors found: 7 in 48 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Simon Fraser (smfr)]

Comment on attachment 286797 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=286797&action=review

> Source/WTF/ChangeLog:36
> +        Registry on Windows, and the `defaults` global domain on macOS. The

Not necessarily the global domain; just a domain that NSUserDefaults picks up.

> Source/WTF/ChangeLog:56
> +        defaults write -g WebCoreLogging -string 'all=---,Network=**+'

This is too crazypants. I'd never be able to parse that in my head.

[Keith Rollin]

(In reply to comment #3)
> Comment on attachment 286797 [details]
> Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=286797&action=review
> 
> > Source/WTF/ChangeLog:36
> > +        Registry on Windows, and the `defaults` global domain on macOS. The
> 
> Not necessarily the global domain; just a domain that NSUserDefaults picks
> up.

Good point.

> > Source/WTF/ChangeLog:56
> > +        defaults write -g WebCoreLogging -string 'all=---,Network=**+'
> 
> This is too crazypants. I'd never be able to parse that in my head.

What would you suggest? I thought of something like full structured JSON strings, but that seemed too crazypants for me.

[Simon Fraser (smfr)]

(In reply to comment #4)
> (In reply to comment #3)
> > Comment on attachment 286797 [details]
> > Patch
> > 
> > View in context:
> > https://bugs.webkit.org/attachment.cgi?id=286797&action=review
> > 
> > > Source/WTF/ChangeLog:36
> > > +        Registry on Windows, and the `defaults` global domain on macOS. The
> > 
> > Not necessarily the global domain; just a domain that NSUserDefaults picks
> > up.
> 
> Good point.
> 
> > > Source/WTF/ChangeLog:56
> > > +        defaults write -g WebCoreLogging -string 'all=---,Network=**+'
> > 
> > This is too crazypants. I'd never be able to parse that in my head.
> 
> What would you suggest? I thought of something like full structured JSON
> strings, but that seemed too crazypants for me.

I think you should break this patch up into several parts:

Part 1: use the com.apple.WebKit subsystem for existing release logging. This would allow us to turn it off with 'log config'
Part 2: use log channel names as categories for release logging. This would allow us to filter by category.
Part 3: There is no part 3? Not sure if controlling release logging through 'defaults' makes sense, and may even cause problems (someone could disable os_logging for webkit by mistake).

[Keith Rollin]

(In reply to comment #5)
> I think you should break this patch up into several parts:
> 
> Part 1: use the com.apple.WebKit subsystem for existing release logging.
> This would allow us to turn it off with 'log config'
> Part 2: use log channel names as categories for release logging. This would
> allow us to filter by category.
> Part 3: There is no part 3? Not sure if controlling release logging through
> 'defaults' makes sense, and may even cause problems (someone could disable
> os_logging for webkit by mistake).

One of the use-cases I was thinking of was someone who wanted to use debug-level logging for some local development. They would want to use debug-level logging so that they would be reasonably sure that it would be disabled in most cases. That way, the code could stay around and be re-enabled on an as-needed basis.

At the same time, I wanted to be able to filter out other logging. The biggest comment I get about this new logging is "what is all this logging and how do I get rid of it?". Someone viewing the logging via Console or the `log` tool can filter it out, but there are also people who use Xcode, which doesn't have advanced filtering facilities. There's an environment variable that controls this somewhat, but it is not flexible enough to filter out default and info logging and keep debug logging. So I extended the current `defaults` mechanism to support them.

In short, I wanted to support someone using Xcode to debug with debug-level logging statements, without any other logging getting in the way. I think that's a common enough scenario that we want to support it, but don't think that just Part 1 & 2 are sufficient to get us all the way there.

I'm not sure how likely Part 3 would be to cause a problem. This logging is intended to help us uncover issues on users' systems. While we may run into the problem of accidentally turning off logging locally, I'm not sure that we'd ever run into that issue in the wild.

[Gavin Barraclough]

This is a very large change, so it's difficult to pick apart, but I think there are at least four separate things going on here:

1) Adding the os_log subsystem.
2) Adding the os_log categories, mapped to our old logging channels.
3) Making os_log runtime switchable, mapped to our old logging channels.
4) Adding debug/info/fault logging.

I think these would be better done as separate patches.

• I think (1) is probably non-contentiously a good idea.

• For (2), I'm not sure that the right way to go for adding os_log categories to release logging is to map these onto the old WK logging channels. The existing mechanism is intended to be debug only, and not designed to be efficient, parsing strings at runtime to discover the set of channels, adds an extra level of indirection, etc. Perhaps it would be better to let logging clients create & pass in their own channels, instead of WTF knowing having to know about all of them? E.g. you could add a ReleaseLogChannel object to set up the channel; FrameLoader could just have a singleton instance of one of these objects so it owned it could own its logging channel.

• For (3), I'd like to be clear on what the goals are here. I think our primary goal here is to have a workaround for current limitation that we don't think we can turn off the release logging when debugging in Xcode. If that is the goal, then remapping RELEASE_LOG not the old logging system seems like a really heavyweight solution. It seems instead we could have a single global bool flag that in DEBUG builds could be used to disable all release logging. Mapping RELEASE_LOG onto the existing logging mechanisms seems to be taking us in the wrong direction, since longer term I don’t think we want to still be using the existing mechanisms even for debug logging. I think we want to find a suitable way to make the old debug logging be better mapped onto os_log mechanisms on Darwin platforms, so we can use the system channel controls rather than relying on our own.

• For (4), I’m not sure that I yet see the value in adding this. In WebKit we have a policy of not keeping dead code in the tree. If we’re adding these functions, we should have a compelling use case of where we think they should be used. If we’re not currently planning to use these mechanisms, I think you should hold off on landing a patch to add them

[Gavin Barraclough]

Actually, Maybe I'm wrong to separate (1) and (2) – since the subsystem is specified in the same object as the category, maybe these two changes do fit together.

[Keith Rollin]

I spent some time yesterday talking with some people about their logging needs.

There was a discussion about submitting support for subsystems and categories separately. But once subsystem support was in place, adding support for categories was a three-line change, so it seemed to make sense to include them together. Support for categories is efficient (there's no string parsing or indirection).

Regarding support for INFO, DEBUG, and FAULT logging, I think we may have cases for these. Safari uses INFO level debugging, so having support for that would help them consolidate their macros onto our facilities. DEBUG logging would be useful for some page-loading issues I'm looking into now. And FAULT logging would be helpful to gather INFO-level logging in the cases where an issue spans the Safari, WebContent, and Networking processes. So I think there's a need for these macros. Even if there isn't they're only a few lines of isolated code. It seems simple enough to include them for the (possibly rare) cases they are needed.

As for some facility to control what logging gets spewed to Xcode, the current mechanism is being removed until we can determine what works best for everyone.

[Keith Rollin]

After discussing with Gavin, support for INFO, DEBUG, and FAULT logging is coming out of this patch. While there are use cases for them, until there is any actual use of them, they should not be included.

[Keith Rollin]

Created attachment 287048 [details]
Patch

[Keith Rollin]

Patch doesn't apply. I'll fix and re-upload.

[Keith Rollin]

Created attachment 287073 [details]
Patch

[WebKit Commit Bot]

Attachment 287073 [details] did not pass style-queue:


ERROR: Source/WTF/wtf/Assertions.h:150:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:155:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:158:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:406:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:409:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:412:  Extra space after ( in function call  [whitespace/parens] [4]
Total errors found: 6 in 48 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[Simon Fraser (smfr)]

Comment on attachment 287073 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=287073&action=review

> Source/WTF/wtf/Assertions.h:160
> +#define LOG_CHANNEL(name) JOIN_LOG_CHANNEL_WITH_PREFIX(LOG_CHANNEL_PREFIX, name)
> +#define LOG_CHANNEL_ADDRESS(name) &LOG_CHANNEL(name),
> +#define JOIN_LOG_CHANNEL_WITH_PREFIX(prefix, channel) JOIN_LOG_CHANNEL_WITH_PREFIX_LEVEL_2(prefix, channel)
> +#define JOIN_LOG_CHANNEL_WITH_PREFIX_LEVEL_2(prefix, channel) prefix ## channel
> +
> +#define DECLARE_LOG_CHANNEL(name) \
> +    extern WTFLogChannel LOG_CHANNEL(name);
> +
> +#if !defined(DEFINE_LOG_CHANNEL)
> +#if RELEASE_LOG_DISABLED
> +#define DEFINE_LOG_CHANNEL(name, subsystem) \
> +    WTFLogChannel LOG_CHANNEL(name) = { WTFLogChannelOff, #name };
> +#else
> +#define DEFINE_LOG_CHANNEL(name, subsystem) \
> +    WTFLogChannel LOG_CHANNEL(name) = { WTFLogChannelOff, #name, subsystem, OS_LOG_DEFAULT };
> +#endif
> +#endif

I feel like we should move all this out of Assertions.h and make wtf/Logging.h at some point.

> Source/WTF/wtf/RefCountedLeakCounter.cpp:45
> +static WTFLogChannel LogRefCountedLeaks = { WTFLogChannelOn, "RefCountedLeaks", "com.apple.WebKit", OS_LOG_DEFAULT };

I think the "com.apple.WebKit" should be in a macro coming from Assertions.h

[Keith Rollin]

Created attachment 287565 [details]
Patch

[WebKit Commit Bot]

Attachment 287565 [details] did not pass style-queue:


ERROR: Source/WTF/wtf/Assertions.h:152:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:157:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:160:  LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
ERROR: Source/WTF/wtf/Assertions.h:408:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:411:  Extra space after ( in function call  [whitespace/parens] [4]
ERROR: Source/WTF/wtf/Assertions.h:414:  Extra space after ( in function call  [whitespace/parens] [4]
Total errors found: 6 in 48 files


If any of these errors are false positives, please file a bug against check-webkit-style.

[WebKit Commit Bot]

Comment on attachment 287565 [details]
Patch

Clearing flags on attachment: 287565

Committed r205275: <http://trac.webkit.org/changeset/205275>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.