Bug 233949 – [WTF] RELEASE_ASSERT_WITH_MESSAGE() should always print the message

• Status: ASSIGNED
• Component: Web Template Framework

[Adrian Perez]

While sending a message to journald is all fine and dandy, in this particular
case we want to make sure people know why WebKit crashed or didn't work correctly
due to a missing GStreamer element.

[Adrian Perez]

Created attachment 446228 [details]
Patch

[Michael Catanzaro]

Comment on attachment 446228 [details]
Patch

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

> Source/WebCore/platform/graphics/gstreamer/GStreamerCommon.cpp:512
> -    RELEASE_ASSERT_WITH_MESSAGE(element, "GStreamer element %s not found. Please install it", factoryName);
> +    if (!element) {
> +        RELEASE_ASSERT_WITH_MESSAGE(false, "GStreamer element %s (factory %s) not found. Please install it", name, factoryName);
> +        WTFLogAlways("Required GStreamer element %s (factory %s) not found. Please install it", name, factoryName);
> +        WTFCrash();
> +    }

Adrian your new code is unreachable. RELEASE_ASSERT() does not return!

[Michael Catanzaro]

> RELEASE_ASSERT() does not return!

Well... not quite, but it really doesn't return when you pass false to it like you're doing here. :P

And this really looks like a workaround for broken RELEASE_ASSERT_WITH_MESSAGE(), right? Does that not currently call WTFLogAlways()? Seems better to fix that instead?

[Adrian Perez]

(In reply to Michael Catanzaro from comment #3)
> > RELEASE_ASSERT() does not return!
> 
> Well... not quite, but it really doesn't return when you pass false to it
> like you're doing here. :P
> 
> And this really looks like a workaround for broken
> RELEASE_ASSERT_WITH_MESSAGE(), right? Does that not currently call
> WTFLogAlways()? Seems better to fix that instead?

Finally got round to check this, here's the relevant bit from wtf/Assertions.h:

  #if !ASSERT_ENABLED
  #define RELEASE_ASSERT(assertion, ...) do { \
      if (UNLIKELY(!(assertion))) \
          CRASH_WITH_INFO(__VA_ARGS__); \
  } while (0)
  #define RELEASE_ASSERT_WITH_MESSAGE(assertion, ...) RELEASE_ASSERT(assertion)
  /* ... */
  #else
  /* ... */
  #endif

Then CRASH_WITH_INFO() is only properly defined for Clang/MSVC:

  #if COMPILER(CLANG) || COMPILER(MSVC)
  /* ... */
  #else
  // GCC does not allow ##__VA_ARGS__ unless GNU extensions are enabled (--std=gnu++NN instead of
  // --std=c++NN) and I think we don't want that, so we'll have a fallback path for GCC. Obviously
  // this will not actually succeed at getting the desired info into registers before crashing, but
  // it's just a fallback anyway.
  //
  // FIXME: When we enable C++20, we should replace ##__VA_ARGS__ with format __VA_OPT__(,) __VA_ARGS__
  // so that we can remove this fallback.
  inline NO_RETURN_DUE_TO_CRASH void CRASH_WITH_INFO(...)
  {
      CRASH();
  }
  /* ... */

And finally CRASH() expands to WTFBreakpointTrap(), neither print anything.

I'll see if I can come up with a definition for CRASH_WITH_INFO() that would do
for GCC.

[Adrian Perez]

I'm splitting a patch for the FIXME in bug #235573

[Adrian Perez]

(In reply to Adrian Perez from comment #5)
> I'm splitting a patch for the FIXME in bug #235573

Do we want to print a more descriptive message for missing GStreamer
elements with a call to WTFLogAlways() or shall we only rely on the
fix for CRASH_WITH_INFO()?

If we think a working CRASH_WITH_INFO() is enough, then we can close
this bug.

[Adrian Perez]

(In reply to Adrian Perez from comment #6)
> (In reply to Adrian Perez from comment #5)
> > I'm splitting a patch for the FIXME in bug #235573
> 
> Do we want to print a more descriptive message for missing GStreamer
> elements with a call to WTFLogAlways() or shall we only rely on the
> fix for CRASH_WITH_INFO()?
> 
> If we think a working CRASH_WITH_INFO() is enough, then we can close
> this bug.

The fix from bug #235573 is not enough: messages are being discarded in
release builds. In release builds ASSERT_ENABLED==0, which means the
following definitions are picked from wtf/Assertions.h:640:

  #if !ASSERT_ENABLED

  #define RELEASE_ASSERT(assertion, ...) do { \
      if (UNLIKELY(!(assertion))) \
          CRASH_WITH_INFO(__VA_ARGS__); \
  } while (0)
  #define RELEASE_ASSERT_WITH_MESSAGE(assertion, ...) RELEASE_ASSERT(assertion)
  // ...

Note how the expansion of RELEASE_ASSERT_WITH_MESSAGE() passes “assertion”
down to RELEASE_ASSERT(), but more importantly it does not pass __VA_ARGS__
along. This means that RELEASE_ASSERT() never gets to see the additional
macro arguments with the message format string and its parameters 🤦️

I think this should planly be:

  #define RELEASE_ASSERT_WITH_MESSAGE(...) RELEASE_ASSERT(__VA_ARGS__)

I'll try to read on the commit log for Assertions.h to try to understand
what's the rationale for the current definitions, but the fact is that we
are missing on printing important messages here.

[Adrian Perez]

(In reply to Adrian Perez from comment #7)

> [...] 
>
> I think this should planly be:
> 
>   #define RELEASE_ASSERT_WITH_MESSAGE(...) RELEASE_ASSERT(__VA_ARGS__)
> 
> I'll try to read on the commit log for Assertions.h to try to understand
> what's the rationale for the current definitions, but the fact is that we
> are missing on printing important messages here.

The fact that there is an ASSERT_MSG_DISABLED macro, but that it does
NOT participate in the definition of RELEASE_ASSERT_WITH_MESSAGE() nor
RELEASE_ASSERT() makes me lean towards thinking that indeed using
RELEASE_ASSERT_WITH_MESSAGE() should not be discarding the message...
otherwise it should discard it or not depending on ASSERT_MSG_DISABLED,
right?

[Adrian Perez]

(In reply to Adrian Perez from comment #8)
> (In reply to Adrian Perez from comment #7)
> 
> > [...] 
> >
> > I think this should planly be:
> > 
> >   #define RELEASE_ASSERT_WITH_MESSAGE(...) RELEASE_ASSERT(__VA_ARGS__)
> > 
> > I'll try to read on the commit log for Assertions.h to try to understand
> > what's the rationale for the current definitions, but the fact is that we
> > are missing on printing important messages here.
> 
> The fact that there is an ASSERT_MSG_DISABLED macro, but that it does
> NOT participate in the definition of RELEASE_ASSERT_WITH_MESSAGE() nor
> RELEASE_ASSERT() makes me lean towards thinking that indeed using
> RELEASE_ASSERT_WITH_MESSAGE() should not be discarding the message...
> otherwise it should discard it or not depending on ASSERT_MSG_DISABLED,
> right?

Also in bug #204445 a new RELEASE_ASSERT_NOT_REACHED_WITH_MESSAGE() macro got
added, which DOES forward __VA_ARGS__ down to RELEASE_ASSERT_WITH_MESSAGE(),
hinting that the intention is for the messages in such macros to trickle down
all the way to where the printing is actually done.

Also, when CRASH_WITH_INFO() was introduced in bug #188123 the added
RELEASE_ASSERT_NOT_REACHED() macros (both versions) do forward __VA_ARGS__,
yet another hint that the extra arguments should trickle down!

[Adrian Perez]

(In reply to Adrian Perez from comment #9)
> (In reply to Adrian Perez from comment #8)
> > (In reply to Adrian Perez from comment #7)
> > 
> > > [...] 
> > >
> > > I think this should planly be:
> > > 
> > >   #define RELEASE_ASSERT_WITH_MESSAGE(...) RELEASE_ASSERT(__VA_ARGS__)
> > > 
> > > I'll try to read on the commit log for Assertions.h to try to understand
> > > what's the rationale for the current definitions, but the fact is that we
> > > are missing on printing important messages here.
> > 
> > The fact that there is an ASSERT_MSG_DISABLED macro, but that it does
> > NOT participate in the definition of RELEASE_ASSERT_WITH_MESSAGE() nor
> > RELEASE_ASSERT() makes me lean towards thinking that indeed using
> > RELEASE_ASSERT_WITH_MESSAGE() should not be discarding the message...
> > otherwise it should discard it or not depending on ASSERT_MSG_DISABLED,
> > right?
> 
> Also in bug #204445 a new RELEASE_ASSERT_NOT_REACHED_WITH_MESSAGE() macro got
> added, which DOES forward __VA_ARGS__ down to RELEASE_ASSERT_WITH_MESSAGE(),
> hinting that the intention is for the messages in such macros to trickle down
> all the way to where the printing is actually done.
> 
> Also, when CRASH_WITH_INFO() was introduced in bug #188123 the added
> RELEASE_ASSERT_NOT_REACHED() macros (both versions) do forward __VA_ARGS__,
> yet another hint that the extra arguments should trickle down!

Got all the way to the end of the repository history: the macro
RELEASE_ASSERT_WITH_MESSAGE() was added with bug #107725 (nine years ago!)
and it did already skip passing the message down in release builds. There
is no rationale I can find about why it's like that, so I am going to send
a patch and try to get a couple of people to review it :]

[Adrian Perez]

(In reply to Adrian Perez from comment #10)
> (In reply to Adrian Perez from comment #9)
> > (In reply to Adrian Perez from comment #8)
> > > (In reply to Adrian Perez from comment #7)
> > > 
> > > > [...] 
> > > >
> > > > I think this should planly be:
> > > > 
> > > >   #define RELEASE_ASSERT_WITH_MESSAGE(...) RELEASE_ASSERT(__VA_ARGS__)
> > > > 
> > > > I'll try to read on the commit log for Assertions.h to try to understand
> > > > what's the rationale for the current definitions, but the fact is that we
> > > > are missing on printing important messages here.
> > > 
> > > The fact that there is an ASSERT_MSG_DISABLED macro, but that it does
> > > NOT participate in the definition of RELEASE_ASSERT_WITH_MESSAGE() nor
> > > RELEASE_ASSERT() makes me lean towards thinking that indeed using
> > > RELEASE_ASSERT_WITH_MESSAGE() should not be discarding the message...
> > > otherwise it should discard it or not depending on ASSERT_MSG_DISABLED,
> > > right?
> > 
> > Also in bug #204445 a new RELEASE_ASSERT_NOT_REACHED_WITH_MESSAGE() macro got
> > added, which DOES forward __VA_ARGS__ down to RELEASE_ASSERT_WITH_MESSAGE(),
> > hinting that the intention is for the messages in such macros to trickle down
> > all the way to where the printing is actually done.
> > 
> > Also, when CRASH_WITH_INFO() was introduced in bug #188123 the added
> > RELEASE_ASSERT_NOT_REACHED() macros (both versions) do forward __VA_ARGS__,
> > yet another hint that the extra arguments should trickle down!
> 
> Got all the way to the end of the repository history: the macro
> RELEASE_ASSERT_WITH_MESSAGE() was added with bug #107725 (nine years ago!)
> and it did already skip passing the message down in release builds. There
> is no rationale I can find about why it's like that, so I am going to send
> a patch and try to get a couple of people to review it :]

Gah, even if we changed RELEASE_ASSERT_WITH_MESSAGE() to pass down the
message, it would go to RELEASE_ASSERT(), then CRASH_WITH_INFO(), then
WTFCrashWithInfo(), WTFCrashWithInfoImpl() and finally there either a
debug interrupt (e.g. int3 on x86_64) or CRASH() — but printing does not
ever happen. We still need to insert a call to WTFLogAlways() somewhere.

[Adrian Perez]

Created attachment 450711 [details]
RFC Patch

[Adrian Perez]

(In reply to Adrian Perez from comment #12)
> Created attachment 450711 [details]
> RFC Patch

With this patch a release build will print messages like the following
on the standard error stream:

  % epiphany -p                    
../Source/WebCore/platform/graphics/gstreamer/GStreamerCommon.cpp:547: GStreamer element appsink not found. Please install it

  (epiphany:54959): epiphany-WARNING **: 10:21:40.474: Web process crashed
  %

When launched from a desktop environment, the messages will end up in the
session log, for example as part of user journal log in a GNOME session:

  % journalctl --user -b0 --grep=GStreamer    
feb 03 10:22:51 momiji gnome-shell[55384]: ../Source/WebCore/platform/graphics/gstreamer/GStreamerCommon.cpp:547: GStreamer element appsink not found. Please install it

Now, I reckon the proposed patch might be a bit too heavy-handed to address
the issue from this bug; so maybe it makes sense to call WTFLogAlways() from
inside makeGStreamerElement(), and leave the discussion about changing the
definition of RELEASE_ASSERT_WITH_MESSAGE() for a separate bug — at least
doing it that way will make it easier to have a relevant message emitted for
missing GStreamer elements landed sooner.

[Adrian Perez]

(In reply to Adrian Perez from comment #12)
> Created attachment 450711 [details]
> RFC Patch

With this patch a release build will print messages like the following
on the standard error stream:

  % epiphany -p                    
../Source/WebCore/platform/graphics/gstreamer/GStreamerCommon.cpp:547: GStreamer element appsink not found. Please install it

  (epiphany:54959): epiphany-WARNING **: 10:21:40.474: Web process crashed
  %

When launched from a desktop environment, the messages will end up in the
session log, for example as part of user journal log in a GNOME session:

  % journalctl --user -b0 --grep=GStreamer    
feb 03 10:22:51 momiji gnome-shell[55384]: ../Source/WebCore/platform/graphics/gstreamer/GStreamerCommon.cpp:547: GStreamer element appsink not found. Please install it

Now, I reckon the proposed patch might be a bit too heavy-handed to address
the issue from this bug; so maybe it makes sense to call WTFLogAlways() from
inside makeGStreamerElement(), and leave the discussion about changing the
definition of RELEASE_ASSERT_WITH_MESSAGE() for a separate bug — at least
doing it that way will make it easier to have a relevant message emitted for
missing GStreamer elements landed sooner.

[Michael Catanzaro]

Comment on attachment 450711 [details]
RFC Patch

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

OK, I like how you fixed RELEASE_ASSERT_WITH_MESSAGE. This is clearly the way to go IMO. The original RELEASE_ASSERT_WITH_MESSAGE() was just broken.

But I'm not sure what you're doing with this VERBOSE_RELEASE_ASSERT().

P.S. I removed [WTF] from the title of this bug because I've never seen that tag used before.

> Source/JavaScriptCore/b3/air/AirAllocateRegistersAndStackByLinearScan.cpp:57
> -#undef RELEASE_ASSERT
> -#define RELEASE_ASSERT(assertion) do { \
> -    if (!(assertion)) { \
> +#define VERBOSE_RELEASE_ASSERT(assertion, ...) do { \
> +    if (UNLIKELY(!(assertion))) { \
>          WTFReportAssertionFailure(__FILE__, __LINE__, WTF_PRETTY_FUNCTION, #assertion); \
> -        CRASH(); \
> +        CRASH_WITH_INFO(__VA_ARGS__); \
>      } \
> -} while (0)
> +} while (false)

I don't understand: why not get rid of this, and change the callers to use your fixed RELEASE_ASSERT_WITH_MESSAGE()?

[Darin Adler]

Comment on attachment 450711 [details]
RFC Patch

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

>> Source/JavaScriptCore/b3/air/AirAllocateRegistersAndStackByLinearScan.cpp:57
>> +} while (false)
> 
> I don't understand: why not get rid of this, and change the callers to use your fixed RELEASE_ASSERT_WITH_MESSAGE()?

I agree. We don’t want to add even more flavors of assertion, especially not in individual source files. These should be in Assertions.h. And we have too many already.

[Adrian Perez]

(In reply to Michael Catanzaro from comment #15)
> Comment on attachment 450711 [details]
> RFC Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=450711&action=review
> 
> OK, I like how you fixed RELEASE_ASSERT_WITH_MESSAGE. This is clearly the
> way to go IMO. The original RELEASE_ASSERT_WITH_MESSAGE() was just broken.

Thanks :)

> But I'm not sure what you're doing with this VERBOSE_RELEASE_ASSERT().
>
> P.S. I removed [WTF] from the title of this bug because I've never seen that
> tag used before.
> 
> > Source/JavaScriptCore/b3/air/AirAllocateRegistersAndStackByLinearScan.cpp:57
> > -#undef RELEASE_ASSERT
> > -#define RELEASE_ASSERT(assertion) do { \
> > -    if (!(assertion)) { \
> > +#define VERBOSE_RELEASE_ASSERT(assertion, ...) do { \
> > +    if (UNLIKELY(!(assertion))) { \
> >          WTFReportAssertionFailure(__FILE__, __LINE__, WTF_PRETTY_FUNCTION, #assertion); \
> > -        CRASH(); \
> > +        CRASH_WITH_INFO(__VA_ARGS__); \
> >      } \
> > -} while (0)
> > +} while (false)
> 
> I don't understand: why not get rid of this, and change the callers to use
> your fixed RELEASE_ASSERT_WITH_MESSAGE()?

Note how the way I changed RELEASE_ASSERT_WITH_MESSAGE() does not print the
condition of the assertion, only the file + line + message; but the local
redefinition of the RELEASE_ASSERT() in these files was printing the failed
assertion condition, and that seemed quite intentional. But I did not want
the local definition to clash with macros from wtf/Assertions.h so I gave
it a different name.

[Michael Catanzaro]

(In reply to Adrian Perez from comment #17) 
> Note how the way I changed RELEASE_ASSERT_WITH_MESSAGE() does not print the
> condition of the assertion, only the file + line + message; but the local
> redefinition of the RELEASE_ASSERT() in these files was printing the failed
> assertion condition, and that seemed quite intentional. But I did not want
> the local definition to clash with macros from wtf/Assertions.h so I gave
> it a different name.

Ah, that's the difference.

I would just pick one behavior or the other for RELEASE_ASSERT_WITH_MESSAGE() and convert everything to use that. No need to have both behaviors. Printing the failing assert seems useful. It's a WebKit bug if it ever prints, after all, so shouldn't matter much either way.

[Adrian Perez]

(In reply to Darin Adler from comment #16)
> Comment on attachment 450711 [details]
> RFC Patch
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=450711&action=review
> 
> >> Source/JavaScriptCore/b3/air/AirAllocateRegistersAndStackByLinearScan.cpp:57
> >> +} while (false)
> > 
> > I don't understand: why not get rid of this, and change the callers to use your fixed RELEASE_ASSERT_WITH_MESSAGE()?
> 
> I agree. We don’t want to add even more flavors of assertion, especially not
> in individual source files. These should be in Assertions.h. And we have too
> many already.

I very much agree, but wasn't completely sure how to go about these macro
definitions local to only some files (see my previous comment on this, too).
I'll look into simplifying and removing the local definitions.

[Adrian Perez]

(In reply to Michael Catanzaro from comment #18)
> (In reply to Adrian Perez from comment #17) 
> > Note how the way I changed RELEASE_ASSERT_WITH_MESSAGE() does not print the
> > condition of the assertion, only the file + line + message; but the local
> > redefinition of the RELEASE_ASSERT() in these files was printing the failed
> > assertion condition, and that seemed quite intentional. But I did not want
> > the local definition to clash with macros from wtf/Assertions.h so I gave
> > it a different name.
> 
> Ah, that's the difference.
> 
> I would just pick one behavior or the other for
> RELEASE_ASSERT_WITH_MESSAGE() and convert everything to use that. No need to
> have both behaviors. Printing the failing assert seems useful. It's a WebKit
> bug if it ever prints, after all, so shouldn't matter much either way.

Yes, I am going to give it a spin and try that 👍️

[Adrian Perez]

Created attachment 450903 [details]
Patch


Here goes one more iteration. This makes it possible to use
RELEASE_ASSERT_WITH_MESSAGE() without format strings (and in
that case it prints only the failed condition of the assertion)
and that way it can be used to replace the local redefinitions
of RELEASE_ASSERT from the JSC files that had them—where the
intention seemed to be that a message of some kind is always
desired even in release builds.

Let me know what do you think of this approach. If you think we
can further simplify, I will be happy to massage the patch a bit
more =)

[Michael Catanzaro]

EWS are sad.

[Radar WebKit Bug Importer]

<rdar://problem/90248537>

[Adrian Perez]

Created attachment 455237 [details]
Patch

Slightly different, in an attempt at making EWS builders happy