WebKit::setCrashReportApplicationSpecificInformation() should also log to WTFLogAlways()

• Component: WebKit2
• Status: RESOLVED FIXED

[David Kilzer (:ddkilzer)]

WebKit::setCrashReportApplicationSpecificInformation() should also log to WTFLogAlways().

We should log to WTFLogAlways() since "Application Specific Information" doesn't always appear.

In the long term, we may simply replace WebKit::setCrashReportApplicationSpecificInformation() with WTFLogAlways().

[David Kilzer (:ddkilzer)]

Created attachment 405168 [details]
Patch v1

[Radar WebKit Bug Importer]

<rdar://problem/66069227>

[David Kilzer (:ddkilzer)]

Comment on attachment 405168 [details]
Patch v1

Adding cq+ because all ports compiled, and this only adds logging when crashing, so it can't affect ios-wk2 layout test results.

[EWS]

Committed r264858: <https://trac.webkit.org/changeset/264858>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 405168 [details].

[Ryan Haddad]

Reverted r264858 for reason:

Caused spurious CRASHING TEST logging during layout test runs

Committed r264870: <https://trac.webkit.org/changeset/264870>

[David Kilzer (:ddkilzer)]

Moving to RESOLVED/WONTFIX.  I'll change the way we log in the two methods in Source/WebKit that use CRASH_WITH_INFO() instead.

[David Kilzer (:ddkilzer)]

Actually, I will use this to re-land the patch.  I'm going to clean up the different code paths that are used to set Application Specific Information, too.

[Radar WebKit Bug Importer]

<rdar://problem/66085705>

[David Kilzer (:ddkilzer)]

Created attachment 405222 [details]
Patch v2

[David Kilzer (:ddkilzer)]

Created attachment 405223 [details]
Patch v3

[David Kilzer (:ddkilzer)]

Comment on attachment 405223 [details]
Patch v3

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

> Source/WebKit/Platform/cocoa/WKCrashReporter.mm:38
> -void setCrashReportApplicationSpecificInformation(CFStringRef infoString)
> +void setCrashReportApplicationSpecificInformation(const char* infoString)
>  {
> -    WTF::setCrashLogMessage([(__bridge NSString *)infoString UTF8String]);
> +    WTFLogAlways("%s", infoString);
> +    WTF::setCrashLogMessage(infoString);
>  }

Thinking about renaming this to WebKit::logAndSetCrashLogMessage().

[Darin Adler]

Comment on attachment 405223 [details]
Patch v3

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

Change looks fine.

> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:276
> +        WebKit::setCrashReportApplicationSpecificInformation([NSString stringWithFormat:@"Unhandled error code %x, message '%s' (%hu)", kr, description(message->messageName()), message->messageName()].UTF8String);

Now that we are trying to make a C string rather than an CFStringRef, we could use WebKit string formatting instead of NSString stuff. It’s easier to use correctly with more type safety. Something like this:

    auto name = message->messageName();
    auto string = makeString("Unhandled error code ", hex(kr, Lowercase) ", message '", description(name), " (", name, ')');
    WebKit::setCrashReportApplicationSpecificInformation(string.utf8().data());

> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:493
> +        WebKit::setCrashReportApplicationSpecificInformation([NSString stringWithFormat:@"Unhandled error code %x from mach_msg, receive port is %x", kr, machPort].UTF8String);

auto string = makeString("Unhandled error code ", hex(kr, Lowercase) ", from mach_msg, receive port is ", hex(machPort, Lowercase));
    WebKit::setCrashReportApplicationSpecificInformation(string.utf8().data());

> Source/WebKit/Shared/Cocoa/AuxiliaryProcessCocoa.mm:37
> +    setCrashReportApplicationSpecificInformation([NSString stringWithFormat:@"Received invalid message: '%s' (%hu)", description(messageName), messageName].UTF8String);

auto string = makeString("Received invalid message: '", description(messageName), "' (", messageName, ')');
    WebKit::setCrashReportApplicationSpecificInformation(string.utf8().data());

> Source/WebKit/Shared/EntryPointUtilities/Cocoa/XPCService/XPCServiceMain.mm:159
> +            setCrashReportApplicationSpecificInformation([NSString stringWithFormat:@"WebKit framework version mismatch: %s != %s", webKitBundleVersion.utf8().data(), expectedBundleVersion.utf8().data()].UTF8String);

auto string = makeString("WebKit framework version mismatch: ", webKitBundleVersion, " != ", expectedBundleVersion);
    WebKit::setCrashReportApplicationSpecificInformation(string.utf8().data());

> Tools/WebKitTestRunner/cocoa/CrashReporterInfo.mm:73
>          String message("CRASHING TEST: ");
>          message = message + testPath;

auto message = makeString("CRASHING TEST: ", testPath);

[Darin Adler]

Comment on attachment 405223 [details]
Patch v3

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

>> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:276
>> +        WebKit::setCrashReportApplicationSpecificInformation([NSString stringWithFormat:@"Unhandled error code %x, message '%s' (%hu)", kr, description(message->messageName()), message->messageName()].UTF8String);
> 
> Now that we are trying to make a C string rather than an CFStringRef, we could use WebKit string formatting instead of NSString stuff. It’s easier to use correctly with more type safety. Something like this:
> 
>     auto name = message->messageName();
>     auto string = makeString("Unhandled error code ", hex(kr, Lowercase) ", message '", description(name), " (", name, ')');
>     WebKit::setCrashReportApplicationSpecificInformation(string.utf8().data());

I think I might have left an "0x" out. Also, if we don’t insist on lowercase hex, then we could omit the Lowercase option. Also might have to include the StringConcatenateNumbers.h and HexNumber.h headers.

auto string = makeString("Unhandled error code 0x", hex(kr) ", message '", description(name), " (", name, ')');

[Simon Fraser (smfr)]

Comment on attachment 405223 [details]
Patch v3

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

> Source/WebKit/Platform/cocoa/WKCrashReporter.mm:36
> +    WTFLogAlways("%s", infoString);

This is called for every test, not just tests that crash, so this will log every time.

[David Kilzer (:ddkilzer)]

Comment on attachment 405223 [details]
Patch v3

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

>> Source/WebKit/Platform/cocoa/WKCrashReporter.mm:36
>> +    WTFLogAlways("%s", infoString);
> 
> This is called for every test, not just tests that crash, so this will log every time.

Yep, I found that out in Patch v1 when it caused all internal layout test bots to think every test crashed, but (surprisingly!) external layout tests bots did not fail due to this change.

This is no longer an issue as this patch changes DumpRenderTree and WebKitTestRunner to call WTF::setCrashLogMessage() directly now (scroll down to the end of the patch).

[Darin Adler]

Seems to be there are two different possible uses of this function:

1) Calling when you know you are about to intentionally crash.

2) Calling to provide background information about context in case you crash, not knowing a crash will happen.

For (2), the proposed implementation is not right. For (1), it’s fine.

[David Kilzer (:ddkilzer)]

(In reply to Darin Adler from comment #16)
> Seems to be there are two different possible uses of this function:
> 
> 1) Calling when you know you are about to intentionally crash.
> 
> 2) Calling to provide background information about context in case you
> crash, not knowing a crash will happen.
> 
> For (2), the proposed implementation is not right. For (1), it’s fine.

There are no instances of (2) after I changed DumpRenderTree and WebKitTestRunner to call WTF::setCrashLogMessage() directly. See Comment #15.

I'm also renaming setCrashReportApplicationSpecificInformation() to logAndSetCrashLogMessage() as mentioned in Comment #11.

[David Kilzer (:ddkilzer)]

Created attachment 405314 [details]
Patch for landing

[Darin Adler]

Comment on attachment 405314 [details]
Patch for landing

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

> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:278
> +        auto messageNameValue = static_cast<std::underlying_type_t<IPC::MessageName>>(messageName);

Could add support for this to StringConcatenateNumbers.h so we don’t have to cast.

> Source/WebKit/Shared/Cocoa/AuxiliaryProcessCocoa.mm:37
> +    auto messageNameValue = static_cast<std::underlying_type_t<IPC::MessageName>>(messageName);

Ditto.

> Tools/DumpRenderTree/mac/DumpRenderTree.mm:1648
> +static void changeWindowScaleIfNeeded(const char* testPathOrUrl)

How about URL instead of Url?

[David Kilzer (:ddkilzer)]

Comment on attachment 405314 [details]
Patch for landing

Marking cq+ with win bot orange and ios-wk2,mac-debug-wk1 layout tests unfinished because:

- The internal bot failures happened due to always logging from DRT and WKTR, and that code path has been fixed.  Ran accessibility tests internally and they were not all marked as crashing.
- This code path in WebKit2 is only used on crashing or (in one case) on a mach message error code path, which isn't something that is tested by layout tests.

[EWS]

Committed r264957: <https://trac.webkit.org/changeset/264957>

All reviewed patches have been landed. Closing bug and clearing flags on attachment 405314 [details].

[David Kilzer (:ddkilzer)]

Comment on attachment 405314 [details]
Patch for landing

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

>> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:278
>> +        auto messageNameValue = static_cast<std::underlying_type_t<IPC::MessageName>>(messageName);
> 
> Could add support for this to StringConcatenateNumbers.h so we don’t have to cast.

Using std::enable_if_t<std::is_enum<E>::value?  Honestly, I looked at StringConcatenate.h, but it wasn't obvious to me how POD values (like int, unsigned, etc.) were handled by the template code, let alone how to add support for generic enum values.

>> Tools/DumpRenderTree/mac/DumpRenderTree.mm:1648
>> +static void changeWindowScaleIfNeeded(const char* testPathOrUrl)
> 
> How about URL instead of Url?

I was going to use URL instead of Url, but then I felt compelled to change `localPathOrUrl` to match the parameter, and I wasn't even sure if anyone had a strong preference, and I didn't want to ask because it could to turn into bike shedding.

I can fix this as a follow-up if you feel strongly about it.

[Darin Adler]

(In reply to David Kilzer (:ddkilzer) from comment #22)
> Using std::enable_if_t<std::is_enum<E>::value?

Yes.

[Darin Adler]

(In reply to David Kilzer (:ddkilzer) from comment #22)
> I was going to use URL instead of Url, but then I felt compelled to change
> `localPathOrUrl` to match the parameter, and I wasn't even sure if anyone
> had a strong preference, and I didn't want to ask because it could to turn
> into bike shedding.

I think the WebKit coding style document specifically addresses this.

[David Kilzer (:ddkilzer)]

(In reply to Darin Adler from comment #24)
> (In reply to David Kilzer (:ddkilzer) from comment #22)
> > I was going to use URL instead of Url, but then I felt compelled to change
> > `localPathOrUrl` to match the parameter, and I wasn't even sure if anyone
> > had a strong preference, and I didn't want to ask because it could to turn
> > into bike shedding.
> 
> I think the WebKit coding style document specifically addresses this.

It's kind of covered implicitly (when talking about lowercasing acronyms at the start of a variable name), but not explicitly in the middle or end of the variable.

<https://webkit.org/code-style-guidelines/#names>

And check-webkit-style doesn't have a check for it (which would be difficult in the general case, but "URL" is a pretty common acronym used in our variables):

$ ./Tools/Scripts/check-webkit-style Tools/DumpRenderTree/mac/DumpRenderTree.mm

[David Kilzer (:ddkilzer)]

(In reply to David Kilzer (:ddkilzer) from comment #22)
> Comment on attachment 405314 [details]
> Patch for landing
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=405314&action=review
> 
> >> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:278
> >> +        auto messageNameValue = static_cast<std::underlying_type_t<IPC::MessageName>>(messageName);
> > 
> > Could add support for this to StringConcatenateNumbers.h so we don’t have to cast.
> 
> Using std::enable_if_t<std::is_enum<E>::value?  Honestly, I looked at
> StringConcatenate.h, but it wasn't obvious to me how POD values (like int,
> unsigned, etc.) were handled by the template code, let alone how to add
> support for generic enum values.

I was missing the existence of Source/WTF/wtf/text/StringConcatenateNumbers.h.

Bug 214906: WTF::makeString() should handle enum values
<https://bugs.webkit.org/show_bug.cgi?id=214906>

[Alex Christensen]

Comment on attachment 405314 [details]
Patch for landing

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

>>>> Source/WebKit/Platform/IPC/cocoa/ConnectionCocoa.mm:278
>>>> +        auto messageNameValue = static_cast<std::underlying_type_t<IPC::MessageName>>(messageName);
>>> 
>>> Could add support for this to StringConcatenateNumbers.h so we don’t have to cast.
>> 
>> Using std::enable_if_t<std::is_enum<E>::value?  Honestly, I looked at StringConcatenate.h, but it wasn't obvious to me how POD values (like int, unsigned, etc.) were handled by the template code, let alone how to add support for generic enum values.
> 
> I was missing the existence of Source/WTF/wtf/text/StringConcatenateNumbers.h.
> 
> Bug 214906: WTF::makeString() should handle enum values
> <https://bugs.webkit.org/show_bug.cgi?id=214906>

There is a generated function named description(MessageName) for this exact purpose.

[Darin Adler]

(In reply to Alex Christensen from comment #27)
> There is a generated function named description(MessageName) for this exact
> purpose.

I think that's a different purpose, involving the *name* of the message. Formatting an enum as an integer when making a string is distinct, and not specific to IPC messages.

[Alex Christensen]

What benefit does printing the invalid number have?  If we have a valid number, we will get a valid name, otherwise description will return "<invalid message name>" and I'm not sure knowing the number will help anything.

[Darin Adler]

Maybe a good point. Printing the number isn’t new to this patch. Maybe it’s not valuable? I’m generally unclear on how we decided what to log and had assumed the number was valuable.

[David Kilzer (:ddkilzer)]

(In reply to Alex Christensen from comment #29)
> What benefit does printing the invalid number have?  If we have a valid
> number, we will get a valid name, otherwise description will return
> "<invalid message name>" and I'm not sure knowing the number will help
> anything.

In this case, the number is going to both os_log() and to a register via CRASH_WITH_INFO().

So you’re saying there is no value in matching those up, or knowing that a particular generated enum has a given value?  I’d actually find it useful in some cases to know the value of the generated enum without having to rebuild the source to regenerate the value.

Is the only concern that someone might log an enum value thinking they were getting a string description instead?  (Most enums in WebKit aren’t generated, so that isn’t even a common issue.)  What’s the worst that could happen?  They would have to go change their logging statement later to add the text description?

Am I missing some other bad behavior?

[Alex Christensen]

What I'm saying is that the description string is all the information you would need, and it's more useful than an integer value.  The only case where printing an integer would give you more information is if you got an invalid value, but I can't imagine needing to know which invalid value you get.  If it's invalid, something has gone horribly wrong and that's all you need to know.

[David Kilzer (:ddkilzer)]

(In reply to Alex Christensen from comment #32)
> What I'm saying is that the description string is all the information you
> would need, and it's more useful than an integer value.  The only case where
> printing an integer would give you more information is if you got an invalid
> value, but I can't imagine needing to know which invalid value you get.  If
> it's invalid, something has gone horribly wrong and that's all you need to
> know.

What if the value is so horribly wrong that description() returns nothing?  Then I'd want the value, too.

[Alex Christensen]

It will always return a valid value or "<invalid message name>", in which case I don't think there's anything useful to get from the invalid value.

[Darin Adler]

Are you going to force me to find the other cases where we already log numeric values of enums? I believe I know how programmers think: I expect I will find them.

I think your position that this should never be done is an interesting proposal!

[David Kilzer (:ddkilzer)]

(In reply to Alex Christensen from comment #34)
> It will always return a valid value or "<invalid message name>", in which
> case I don't think there's anything useful to get from the invalid value.

Alex, do you only object to logging IPC::MessageName specifically, or all enum values in general?  Because I don't think it's practical to write description() methods for any enum value that someone might want to log in the future.

Also, I disagree that an invalid value is not interesting.

- When debugging an IPC failure, it's only uninteresting until we understand why we got the invalid value in the first place.

- Also, we can't assume every invalid value would be exactly the same if "<invalid message name>" is returned.  We could get a group of invalid values that are different (such as with a memory smasher), and just logging "<invalid message name>" would be nearly useless other than to know that an invalid value was passed.  Conversely, a group of invalid values that are all the same tells us something different is probably happening other than a memory smasher.