Bug 166474 – ASSERT_NOT_REACHED() should always log error messages in Release builds

• Component: Web Template Framework
• Status: NEW

[David Kilzer (:ddkilzer)]

We should always log an error message when an ASSERT_NOT_REACHED() is hit in Release builds.

[David Kilzer (:ddkilzer)]

<rdar://problem/29786543>

[David Kilzer (:ddkilzer)]

Created attachment 297741 [details]
Patch v1

[WebKit Commit Bot]

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


ERROR: Source/WTF/wtf/Assertions.h:271:  DECLARE_LOG_CHANNEL is incorrectly named. Don't use underscores in your identifier names.  [readability/naming/underscores] [4]
Total errors found: 1 in 3 files


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

[David Kilzer (:ddkilzer)]

Comment on attachment 297741 [details]
Patch v1

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

> Source/WTF/wtf/Assertions.h:285
> +#define ASSERT_NOT_REACHED() (RELEASE_LOG_ERROR_CHANNEL(JOIN_LOG_CHANNEL_WITH_PREFIX(WTF_LOG_CHANNEL_PREFIX, Assertion), "%s (%s:%d): ASSERT_NOT_REACHED", WTF_PRETTY_FUNCTION, __FILE__, __LINE__))

Actually, the reason I can't #define LOG_CHANNEL_PREFIX before this statement, then #undef LOG_CHANNEL_PREFIX after this statement and then use RELEASE_LOG_ERROR(), is that RELEASE_LOG_ERROR() is defined after this macro.

Would it be worth moving the RELEASE_LOG* definitions above this, or moving these ASSERT* macros below?

[Darin Adler]

This violates a common property of all ASSERT macros; none of them do anything if assertions are disabled. Do we really need to have ASSERT_NOT_REACHED do something different from ASSERT(false)?

If there are some ASSERT_NOT_REACHED that are so important that we want them even in release builds we could name them something like RELEASE_ASSERT_NOT_REACHED.

Or maybe there is some argument for having ASSERT_NOT_REACHED be unconditional.

[David Kilzer (:ddkilzer)]

(In reply to comment #5)
> This violates a common property of all ASSERT macros; none of them do
> anything if assertions are disabled. Do we really need to have
> ASSERT_NOT_REACHED do something different from ASSERT(false)?
> 
> If there are some ASSERT_NOT_REACHED that are so important that we want them
> even in release builds we could name them something like
> RELEASE_ASSERT_NOT_REACHED.
> 
> Or maybe there is some argument for having ASSERT_NOT_REACHED be
> unconditional.

Yes, I think this is the first step to changing ASSERT_NOT_REACHED to RELEASE_ASSERT_NOT_REACHED and removing ASSERT_NOT_REACHED.

Using ASSERT_NOT_REACHED is like saying, "I don't think this will ever get hit, but I'm afraid to use RELEASE_ASSERT_NOT_REACHED."  Either the code path is hit or it's not, and using ASSERT_NOT_REACHED will never tell us.

I suspect there are bugs caused by code hitting the ASSERT_NOT_REACHED path, but we'll never know unless we get precise steps to reproduce AND reproduce with a Debug build.

This also starts to turn a reactive mechanism into a proactive mechanism.

We don't (yet) want to enable logging for every ASSERT(<false condition>)) because that's too big of a step to do at once.

[Saam Barati]

Comment on attachment 297741 [details]
Patch v1

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

> Source/WTF/ChangeLog:17
> +        If this change is blamed for performance regressions, it's
> +        because an ASSERT_NOT_REACHED() is being hit unexpectedly, not
> +        because of this patch.  The ASSERT_NOT_REACHED() being hit
> +        should be investigated.

I'm not sure this is strictly guaranteed to be the case. Because we're actually emitting code now for this, it may change how things are compiled. It could also effect icache performance.
(That said, I'm not sure what the code compiles to on release builds for ASSERT_NOT_REACHED())

[David Kilzer (:ddkilzer)]

Comment on attachment 297741 [details]
Patch v1

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

>> Source/WTF/ChangeLog:17
>> +        should be investigated.
> 
> I'm not sure this is strictly guaranteed to be the case. Because we're actually emitting code now for this, it may change how things are compiled. It could also effect icache performance.
> (That said, I'm not sure what the code compiles to on release builds for ASSERT_NOT_REACHED())

It's defined as ((void)0), but may depend on the context?

[Saam Barati]

(In reply to comment #8)
> Comment on attachment 297741 [details]
> Patch v1
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=297741&action=review
> 
> >> Source/WTF/ChangeLog:17
> >> +        should be investigated.
> > 
> > I'm not sure this is strictly guaranteed to be the case. Because we're actually emitting code now for this, it may change how things are compiled. It could also effect icache performance.
> > (That said, I'm not sure what the code compiles to on release builds for ASSERT_NOT_REACHED())
> 
> It's defined as ((void)0), but may depend on the context?

I'm wondering what the logging code will be compiled as.

[David Kilzer (:ddkilzer)]

Rough count of ASSERT_NOT_REACHED() macros used in each project:

$ for F in `ls Source`; do echo -n "$F:"; grep -r ASSERT_NOT_REACHED Source/$F | grep -v RELEASE_ASSERT_NOT_REACHED | wc -l; done | grep -v ' 0$'
JavaScriptCore:     236
WTF:      24
WebCore:    1406
WebKit:     509
WebKit2:     352

Compared to RELEASE_ASSERT_NOT_REACHED():

$ for F in `ls Source`; do echo -n "$F:"; grep -r RELEASE_ASSERT_NOT_REACHED Source/$F | wc -l; done | grep -v ' 0$'
JavaScriptCore:     702
WTF:      12
WebCore:      48
WebKit:       3
WebKit2:       8

That's more ASSERT_NOT_REACHED() and fewer RELEASE_ASSERT_NOT_REACHED() (relatively speaking) than I expected!

In light of Darin's feedback, I was going to prepare a patch that simply replaced ASSERT_NOT_REACHED() with RELEASE_ASSERT_NOT_REACHED(), but maybe this requires an extended discussion on webkit-dev?

[Brent Fulgham]

(In reply to comment #10)
> Rough count of ASSERT_NOT_REACHED() macros used in each project:
> 
> $ for F in `ls Source`; do echo -n "$F:"; grep -r ASSERT_NOT_REACHED
> Source/$F | grep -v RELEASE_ASSERT_NOT_REACHED | wc -l; done | grep -v ' 0$'
> JavaScriptCore:     236
> WTF:      24
> WebCore:    1406
> WebKit:     509
> WebKit2:     352
> 
> Compared to RELEASE_ASSERT_NOT_REACHED():
> 
> $ for F in `ls Source`; do echo -n "$F:"; grep -r RELEASE_ASSERT_NOT_REACHED
> Source/$F | wc -l; done | grep -v ' 0$'
> JavaScriptCore:     702
> WTF:      12
> WebCore:      48
> WebKit:       3
> WebKit2:       8

It sure seems like one of our most performance-sensitive sections of our code is far more liberal with "RELEASE_ASSERT_NOT_REACHED" than other parts of the system.

I think we are placing a higher priority on our fear that this will have some performance impact (for which there is little or no evidence) than on the very positive impact of identifying and fixing these cases.

I feel that we should switch from ASSERT_NOT_REACHED to RELEASE_ASSERT_NOT_REACHED for these cases, and work with Gavin and his team to assess any performance impact. If it is noticeable, we can always back it out.

The other option is to allow a Release build target that makes these 'Release' assertions, but leaves them inert on Production builds.

[Brent Fulgham]

(In reply to comment #5)
> This violates a common property of all ASSERT macros; none of them do
> anything if assertions are disabled. Do we really need to have
> ASSERT_NOT_REACHED do something different from ASSERT(false)?
> 
> If there are some ASSERT_NOT_REACHED that are so important that we want them
> even in release builds we could name them something like
> RELEASE_ASSERT_NOT_REACHED.
> 
> Or maybe there is some argument for having ASSERT_NOT_REACHED be
> unconditional.

Darin:

Causing this macro to log in release builds seems like a good thing to me, because it will help us see if this is happening on production systems. We suspect this is the case, but we do not have hard evidence that this is true.

Currently, the dormant ASSERT_NOT_REACHED is seen as a "harmless" state, even though it  leads to unknown mayhem after we continue past that statement.

Switching to 'RELEASE_ASSERT_NOT_REACHED' makes this a hard crash at the point of failure, which is great when testing, but would be a negative user experience.

For that reason, I am in favor of making this a "logging" assertion so that we can review log data after getting reports of strange behavior.

Would calling this something like "SHOULD_NEVER_BE_REACHED()" (getting rid of the 'ASSERT' nomenclature) be more palatable?

Or perhaps "ASSERT_OR_LOG_IF_REACHED"?

[Darin Adler]

(In reply to comment #12)
> For that reason, I am in favor of making this a "logging" assertion so that
> we can review log data after getting reports of strange behavior.

Sounds OK.

> Would calling this something like "SHOULD_NEVER_BE_REACHED()" (getting rid
> of the 'ASSERT' nomenclature) be more palatable?

Maybe.

> Or perhaps "ASSERT_OR_LOG_IF_REACHED"?

Also seems like a reasonable suggestion but so wordy.

Both of those ideas sound file.

[Geoffrey Garen]

I think it's an anti-pattern to insert complex logging code into ASSERT macros.

1. Information recovery. We've done a lot of work to remove all the junk from ASSERT macros because it tends to trash stack and register state, erasing all the useful information from crash logs.

Note that RELEASE_ASSERT_NOT_REACHED() just invokes CRASH(). That's the best thing to do if we want to get logging from the field.

If there are any cases of ASSERT_NOT_REACHED() that should be RELEASE_ASSERT_NOT_REACHED(), we should upgrade them by changing to RELEASE_ASSERT_NOT_REACHED(), and not by adding logging to ASSERT_NOT_REACHED().

2. Performance. My concern is not just that existing ASSERT_NOT_REACHED() call sites might get slower but also that all future code that is both complex and performance-sensitive -- in other words, all the code I work on all the time -- must now worry any time it adds an ASSERT. That should never be a worry. Adding assertions to complex code should be a zero-friction experience.

3. Burden of proof. I don't think the burden of proof for a sweeping change like this should be on Gavin's team to show that performance got worse. Instead, whoever makes a sweeping change should do the performance evaluation before landing.

[Brent Fulgham]

(In reply to comment #14)
> I think it's an anti-pattern to insert complex logging code into ASSERT
> macros.
> 
> [... Reasons ... ]

Okay. Then let's switch these ASSERT_NOT_REACHED cases to RELEASE_ASSERT_NOT_REACHED.

We should get pretty quick feedback from STP if this introduces stability issues.

[Brady Eidson]

Comment on attachment 297741 [details]
Patch v1

Patches that have been up for review since 2016 are almost certainly too stale to be relevant to trunk in their current form.

If this patch is still important please rebase it and post it for review again.