As Michael Catanzaro noted on webkit-dev, RELEASE_LOG currently requires os_log (a Cocoa only function) to work. This seems like a mistake, and it really should fallback to using the default logging infrastructure for platforms without os_log.
Just to provide some context, while the ultimate implementation may still be considered a mistake, it was something I gave some thought to. The LOG macros and their underlying infrastructure were created (so I assume) for debugging at development time. The circumstances under which that logging is enabled and the disposition of that logging reflects that model. The logging is enabled on a channel-by-channel basis, and is streams to the terminal, Xcode console, or similar. The RELEASE_LOG macros are for capturing information on a user's system so that it can be collected later for post-molten diagnosis. It's always-on, and is not streamed to an in-your-face console. Instead, it's stored in a combination of in-memory and on-disk databases. Because of these two different models, use-cases, etc., I opted to keep the facilities separate, and to let the maintainers of other platforms provide whatever underpinnings for RELEASE_LOG that worked best for them. So rather than have RELEASE_LOG fall back onto LOG or its underlying facility, I'd see something new and platform-appropriate be added. But that's just what I was thinking at the time. Others may have different opinions.
Separate from what logging is desirable, there’s a performance-related question too: On an operating system where there is no super-low-cost logging mechanism like os_log, it might not be right to log those same messages through a higher cost logging mechanism.
Thanks for the historical context Keith. I still think that at the very least, having RELEASE_LOG() act like LOG(), that is, only work in Debug builds, on platforms without os_log, makes sense as many of these logs would also be helpful for debug logging purproses. I don't think that would have the same performance concerns. It might also be helpful to some of this context in the source, so other port maintainers can understand the tradeoffs of enabling RELEASE_LOG() to log in Release builds.
For what it’s worth, I agree with Sam on both of those points.
The Linux equivalent of os_log would be sd-journal [1] from libsystemd (which we would want to be an optional dependency, not required), but I'm not familiar with it, nor am I convinced it's as low-cost as os_log, which sounds impressive. Not sure if using sd-journal would really make a ton of sense for WebKit, because WebKit is only a system library, not a system service. Falling back to debug LOG() makes a lot of sense to me. [1] https://www.freedesktop.org/software/systemd/man/sd-journal.html
(In reply to Michael Catanzaro from comment #5) > The Linux equivalent of os_log would be sd-journal [1] from libsystemd > (which we would want to be an optional dependency, not required), but I'm > not familiar with it, nor am I convinced it's as low-cost as os_log, which > sounds impressive. I've started working on a patch for optional sd-journal support... > Not sure if using sd-journal would really make a ton of > sense for WebKit, because WebKit is only a system library, not a system > service. > Well, AFAIU on mac platforms it's not a system service either?
I’d love to help explain the role of the WebKit framework on macOS, but I don’t know what "system library" or "system service" mean so I can’t easily help.
I wanted to know about sd-journal, so I found this document https://docs.google.com/document/pub?id=1IC9yOXj7j6cdLLxWEBAGRL6wl97tFxgjLUEHIX3MSTs. I got to it from http://0pointer.de/blog/projects/the-journal.html, so I believe that article is from Mr. systemd, Lennart Poettering. I haven't read it yet, but I intend to. But I also wanted to mention something about our RELEASE_LOGging. First, we're making more and more use of it, since we're finding it very valuable for its intended goal of gathering post-mortem information from testers and customers. Second, be very conscious of os_log's own goals of being very fast and space efficient. For example, I gathered the last two minutes of logging on my system. The binary files were 119MB, with the textual expansion being 477MB. For another data point, I collected all the logging on my system. The binary files, covering 2-3 weeks of activity, were 1.3GB; their textual expansion was 7.5GB. Since we watch WebKit's performance very closely, we know that we are gathering this information without appreciable or even noticeable performance slowdown.
(In reply to Darin Adler from comment #7) > I’d love to help explain the role of the WebKit framework on macOS, but I > don’t know what "system library" or "system service" mean so I can’t easily > help. Sorry Darin, by system service I actually meant system library. I think what Michael means with is that WebKit-based apps on Linux are not the usual programs that log data to OS-level logging facilities, such as system-wide daemons, for instance. That's just my interpretation though, Michael please correct me if I am misinterpreting your comment. Anyways, I think sd-journal could be used... As long as it can easily be disabled at compile-time and that it doesn't have a negative impact otherwise, of course.
Honestly, I have no clue what I meant when I wrote that comment. I don't see any reason WebKit should not log to the journal by default.
Created attachment 391153 [details] Patch
Created attachment 391157 [details] Patch
I guess talk to Adrian about how to fix the EWS: -- Could NOT find SYSTEMD (missing: SYSTEMD_INCLUDE_DIRS SYSTEMD_LIBRARIES) (found version "") CMake Error at Source/cmake/OptionsGTK.cmake:462 (message): libsystemd is needed for ENABLE_RELEASE_LOGGING Call Stack (most recent call first): Source/cmake/WebKitCommon.cmake:57 (include) CMakeLists.txt:169 (include)
Comment on attachment 391157 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=391157&action=review Thanks, having release logs is going to be a huge improvement. > Source/WTF/wtf/Assertions.h:541 > +#define RELEASE_LOG(channel, ...) SD_JOURNAL_SEND(channel, LOG_NOTICE, __VA_ARGS__) > +#define RELEASE_LOG_ERROR(channel, ...) SD_JOURNAL_SEND(channel, LOG_ERR, __VA_ARGS__) > +#define RELEASE_LOG_FAULT(channel, ...) SD_JOURNAL_SEND(channel, LOG_CRIT, __VA_ARGS__) > +#define RELEASE_LOG_INFO(channel, ...) SD_JOURNAL_SEND(channel, LOG_INFO, __VA_ARGS__) Ideally LOG_ERR and LOG_CRIT would also print to stderr in addition to the journal, yes? Because these are important error messages, and you shouldn't need to inspect the journal to see important error messages. And since stderr is already going to be printed to the journal, that implies that it might be best to just use g_warning() or g_critical() for these (respectively) and reserve SD_JOURNAL_SEND() for vanilla RELEASE_LOG() and RELEASE_LOG_INFO()... yes? Does that make sense? What do you think? > Source/WTF/wtf/Assertions.h:552 > +#define RELEASE_LOG_WITH_LEVEL(channel, logLevel, ...) do { \ > + if (LOG_CHANNEL(channel).level >= (logLevel)) \ > + SD_JOURNAL_SEND(channel, LOG_INFO, __VA_ARGS__); \ > +} while (0) > + > +#define RELEASE_LOG_WITH_LEVEL_IF(isAllowed, channel, logLevel, ...) do { \ > + if ((isAllowed) && LOG_CHANNEL(channel).level >= (logLevel)) \ > + SD_JOURNAL_SEND(channel, LOG_INFO, __VA_ARGS__); \ > +} while (0) > +#endif Then if you agree with that suggestion, here you would check the level to decide whether to use SD_JOURNAL_SEND() or not. > Source/WTF/wtf/Logger.h:33 > +// Don't send call site informations to the journal because those would always information > Source/WTF/wtf/Logger.h:36 > +#define SD_JOURNAL_SUPPRESS_LOCATION > +#include <systemd/sd-journal.h> This is really sensitive to include order. If Assertions.h gets included before Logger.h, this doesn't work. I'd define this also in Assertions.h, to be safe. > Source/cmake/FindSystemd.cmake:5 > +# Once done, this will define > +# > +# SYSTEMD_INCLUDE_DIRS - the SYSTEMD include drectories > +# SYSTEMD_LIBRARIES - link these to use SYSTEMD Don is going to throw a fit as he's trying to convert find modules to use targets. See r256731 for example of how much nicer it is to use targets instead. You can coordinate with him to figure out what exactly FindSystemd.cmake should look like, but I'm pretty sure he's going to want it to define a target rather than SYSTEMD_INCLUDE_DIRS or SYSTEMD_LIBRARIES. > Source/cmake/OptionsGTK.cmake:90 > +WEBKIT_OPTION_DEFINE(ENABLE_RELEASE_LOGGING "Whether to enable sd-journal logging" PUBLIC ON) I would name it USE_SYSTEMD instead, since I'm also going to want to use libsystemd to run web processes in isolated systemd scopes, and it'd be nice to have only one public build option to disable all use of libsystemd instead of multiple options. ( > Source/cmake/OptionsGTK.cmake:459 > + message(STATUS "Release logs will be sent to the SystemD journal") systemd
(In reply to Michael Catanzaro from comment #14) > Don is going to throw a fit as he's trying to convert find modules to use > targets. See r256731 for example of how much nicer it is to use targets > instead. You can coordinate with him to figure out what exactly > FindSystemd.cmake should look like, but I'm pretty sure he's going to want > it to define a target rather than SYSTEMD_INCLUDE_DIRS or SYSTEMD_LIBRARIES. Talked to Don. Use r256601 as example of how to add a modern find module. I'm sure he'd appreciate not having to update this one himself. ;)
Comment on attachment 391157 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=391157&action=review >> Source/cmake/FindSystemd.cmake:5 >> +# SYSTEMD_LIBRARIES - link these to use SYSTEMD > > Don is going to throw a fit as he's trying to convert find modules to use targets. See r256731 for example of how much nicer it is to use targets instead. You can coordinate with him to figure out what exactly FindSystemd.cmake should look like, but I'm pretty sure he's going to want it to define a target rather than SYSTEMD_INCLUDE_DIRS or SYSTEMD_LIBRARIES. Yes please follow along with some of the updated CMake modules. See FindOpenJPEG.cmake for something you can copy pasta and modify accordingly. There's also FindSQLite3.cmake and FindFontconfig.cmake in there which are roughly the same minus the finding of version numbers. Then just use the created systemd target instead of using the ${SYSTEMD_*} ones.
Comment on attachment 391157 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=391157&action=review >> Source/WTF/wtf/Assertions.h:541 >> +#define RELEASE_LOG_INFO(channel, ...) SD_JOURNAL_SEND(channel, LOG_INFO, __VA_ARGS__) > > Ideally LOG_ERR and LOG_CRIT would also print to stderr in addition to the journal, yes? Because these are important error messages, and you shouldn't need to inspect the journal to see important error messages. And since stderr is already going to be printed to the journal, that implies that it might be best to just use g_warning() or g_critical() for these (respectively) and reserve SD_JOURNAL_SEND() for vanilla RELEASE_LOG() and RELEASE_LOG_INFO()... yes? Does that make sense? What do you think? Kinda makes sense, but by using g_warning/g_critical we lose the channel information.
Comment on attachment 391157 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=391157&action=review >> Source/WTF/wtf/Logger.h:36 >> +#include <systemd/sd-journal.h> > > This is really sensitive to include order. If Assertions.h gets included before Logger.h, this doesn't work. I'd define this also in Assertions.h, to be safe. Thing is, thanks to the usage of macros for logging in Assertions.h, we can get accurate call site information sent to sd-journal. Which isn't the case for the method-based approach used in the Logger :(
(In reply to Philippe Normand from comment #18) > Comment on attachment 391157 [details] > Patch > > View in context: > https://bugs.webkit.org/attachment.cgi?id=391157&action=review > > >> Source/WTF/wtf/Assertions.h:541 > >> +#define RELEASE_LOG_INFO(channel, ...) SD_JOURNAL_SEND(channel, LOG_INFO, __VA_ARGS__) > > > > Ideally LOG_ERR and LOG_CRIT would also print to stderr in addition to the journal, yes? Because these are important error messages, and you shouldn't need to inspect the journal to see important error messages. And since stderr is already going to be printed to the journal, that implies that it might be best to just use g_warning() or g_critical() for these (respectively) and reserve SD_JOURNAL_SEND() for vanilla RELEASE_LOG() and RELEASE_LOG_INFO()... yes? Does that make sense? What do you think? > > Kinda makes sense, but by using g_warning/g_critical we lose the channel > information. How about using g_log_structured(), then? We can pass journald field names to it, therefore we can set CHANNEL+SUBSYSTEM, and the default GLib log handler will automatically print to stderr the messages with level warning and higher, and allow using the “G_MESSAGES_DEBUG” environment variable to configure what to log (as expected for any libraries and applications which use GLib): GUniquePtr<char> messageId(g_uuid_string_random()); g_log_structured(logDomain, G_LOG_LEVEL_WARNING, "MESSAGE_ID", messageId, "CHANNEL", channel.name., "SUBSYSTEM", channel.subsystem, "CODE_FILE", sourceFileName, // If available. "CODE_LINE", sourceFileLine, // Ditto. "CODE_FUNC", sourceFunction, // Ditto. "MESSAGE", logMessage.utf8().data()); I am not 100% sure what to pass as “logDomain”, but we could as well pass the “G_LOG_DOMAIN” constant to it, and then arrange things in CMake to pass e.g. “-DG_LOG_DOMAIN="WebKit-WebCore"”, “-DG_LOG_DOMAIN="WebKit-JSC"”, “-DG_LOG_DOMAIN="WebKit-UIProcess"” and so on for the different components. Reference for g_log_structured() here: https://developer.gnome.org/glib/stable/glib-Message-Logging.html#g-log-structured (BTW, I think it would be fine to land this first without adding the additional code to either user stderr or the GLib logging; that can be done in a follow-up patch.)
(In reply to Philippe Normand from comment #19) > Comment on attachment 391157 [details] > Patch > > View in context: > https://bugs.webkit.org/attachment.cgi?id=391157&action=review > > >> Source/WTF/wtf/Logger.h:36 > >> +#include <systemd/sd-journal.h> > > > > This is really sensitive to include order. If Assertions.h gets included before Logger.h, this doesn't work. I'd define this also in Assertions.h, to be safe. > > Thing is, thanks to the usage of macros for logging in Assertions.h, we can > get accurate call site information sent to sd-journal. Which isn't the case > for the method-based approach used in the Logger :( Most of the logging that goes through Logger use the macros in LoggerHelper.h. You could modify those to (optionally?) include more accurate call site information if necessary.
(In reply to Adrian Perez from comment #20) > How about using g_log_structured(), then? We can pass journald field > names to it, therefore we can set CHANNEL+SUBSYSTEM, and the default > GLib log handler will automatically print to stderr the messages with > level warning and higher, and allow using the “G_MESSAGES_DEBUG” > environment variable to configure what to log (as expected for any > libraries and applications which use GLib) Good idea.
Created attachment 391397 [details] Patch
Comment on attachment 391397 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=391397&action=review > Source/WTF/wtf/PlatformGTK.cmake:72 > + ${SYSTEMD_INCLUDE_DIRS} This shouldn't be needed. Include dirs should be propagated by the Systemd::Systemd target.
(In reply to Michael Catanzaro from comment #22) > (In reply to Adrian Perez from comment #20) > > How about using g_log_structured(), then? We can pass journald field > > names to it, therefore we can set CHANNEL+SUBSYSTEM, and the default > > GLib log handler will automatically print to stderr the messages with > > level warning and higher, and allow using the “G_MESSAGES_DEBUG” > > environment variable to configure what to log (as expected for any > > libraries and applications which use GLib) > > Good idea. I've tested this idea, but then I can't easily filter messages by channel. Also logs are not sent to the journal unless the app requests it.
Created attachment 391518 [details] Patch
Created attachment 392549 [details] Patch
Rebased... Would someone like to review this before it bitrots?
Comment on attachment 392549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=392549&action=review > Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.cpp:63 > + , m_logIdentifier(mediaSource->nextSourceBufferLogIdentifier()) Can mediaSource be nullptr? If yes, this is a potential segfault, otherwise mediaSource should be passed by reference > Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.h:88 > + const Logger& logger() const final { return m_logger.get(); } Why not just return m_mediaSource->logger() here instead of copying Ref<Logger>? And similarly in other cases like this, where lifetimes of two objects are tied to each other
Comment on attachment 392549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=392549&action=review >> Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.cpp:63 >> + , m_logIdentifier(mediaSource->nextSourceBufferLogIdentifier()) > > Can mediaSource be nullptr? If yes, this is a potential segfault, otherwise mediaSource should be passed by reference Can't be nullptr. I agree a ref would make sense here but would rather address this issue in a separate follow-up patch. I haven't closely followed the design of the SourceBuffer/MediaSource relationship, it seems like some changes could be made across the range of supported platforms here. >> Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.h:88 >> + const Logger& logger() const final { return m_logger.get(); } > > Why not just return m_mediaSource->logger() here instead of copying Ref<Logger>? And similarly in other cases like this, where lifetimes of two objects are tied to each other I've just used the same approach as in the AVF impl, TBH.
Comment on attachment 392549 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=392549&action=review >>> Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.cpp:63 >>> + , m_logIdentifier(mediaSource->nextSourceBufferLogIdentifier()) >> >> Can mediaSource be nullptr? If yes, this is a potential segfault, otherwise mediaSource should be passed by reference > > Can't be nullptr. I agree a ref would make sense here but would rather address this issue in a separate follow-up patch. I haven't closely followed the design of the SourceBuffer/MediaSource relationship, it seems like some changes could be made across the range of supported platforms here. Agreed >>> Source/WebCore/platform/graphics/gstreamer/mse/SourceBufferPrivateGStreamer.h:88 >>> + const Logger& logger() const final { return m_logger.get(); } >> >> Why not just return m_mediaSource->logger() here instead of copying Ref<Logger>? And similarly in other cases like this, where lifetimes of two objects are tied to each other > > I've just used the same approach as in the AVF impl, TBH. Looks like premature pessimization to me - extra reference churn, extra fields in objects (which in this case will remain in release builds)
Created attachment 393642 [details] Patch
Comment on attachment 393642 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=393642&action=review > Source/cmake/FindSystemd.cmake:55 > +include(FindPkgConfig) Please use find_package(PkgConfig QUIET) instead. Including find modules is wrong and causes (rightful) warnings witn CMake 3.17
Is that your only comment? Please make a full review so we can avoid un-necessary micro-iterations of the patch.
Comment on attachment 393642 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=393642&action=review > Source/cmake/OptionsWPE.cmake:76 > +WEBKIT_OPTION_DEFINE(USE_SYSTEMD "Whether to enable sd-journal logging" PUBLIC ON) Is "sd-journal logging" an official term? I guess "journald logging" might be more obvious for users
(In reply to Philippe Normand from comment #34) > Is that your only comment? Please make a full review so we can avoid > un-necessary micro-iterations of the patch. I think I have no more comments, except previous concern about Ref churn
Comment on attachment 393642 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=393642&action=review Did not review the whole patch, but one small comment > Source/WTF/wtf/Assertions.h:169 > +#if USE(OS_LOG) > __unsafe_unretained os_log_t osLogChannel; > #endif > +#endif I prefer separate #if vs. nested #if for cases like this: #endif #if USE(OS_LOG) && !RELEASE_LOG_DISABLED __unsafe_unretained os_log_t osLogChannel; #endif This applies in other places below too. I suggest writing the whole expression.
Created attachment 393740 [details] Patch
Committed r258547: <https://trac.webkit.org/changeset/258547>
<rdar://problem/60538783>
In the gtk build with -DUSE_SYSTEMD=OFF, I am getting the following build errors: /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:436:24: error: 'class WebCore::MediaPlayer' has no member named 'mediaPlayerLogger' 436 | , m_logger(player->mediaPlayerLogger()) | ^~~~~~~~~~~~~~~~~ /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:437:31: error: 'class WebCore::MediaPlayer' has no member named 'mediaPlayerLogIdentifier' 437 | , m_logIdentifier(player->mediaPlayerLogIdentifier()) | ^~~~~~~~~~~~~~~~~~~~~~~~ /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp: In member function 'virtual WTFLogChannel& WebCore::MediaPlayerPrivateGStreamer::logChannel() const': /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3844:21: error: 'LogMedia' is not a member of 'WebCore' 3844 | return WebCore::LogMedia; | ^~~~~~~~
Comment on attachment 393740 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=393740&action=review Indeed, a few #if checks are missing > Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:435 > +#endif #if !RELEASE_LOG_DISABLED > Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h:121 > + , public CanMakeWeakPtr<MediaPlayerPrivateGStreamer, WeakPtrFactoryInitialization::Eager> #if !RELEASE_LOG_DISABLED > Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.h:543 > #endif #if !RELEASE_LOG_DISABLED > Source/WebCore/platform/graphics/gstreamer/mse/MediaPlayerPrivateGStreamerMSE.h:85 > #if !RELEASE_LOG_DISABLED
(In reply to Jim Mason from comment #41) > In the gtk build with -DUSE_SYSTEMD=OFF, I am getting the following build > errors: > > /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/ > platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:436:24: error: > 'class WebCore::MediaPlayer' has no member named 'mediaPlayerLogger' > 436 | , m_logger(player->mediaPlayerLogger()) > | ^~~~~~~~~~~~~~~~~ > /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/ > platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:437:31: error: > 'class WebCore::MediaPlayer' has no member named 'mediaPlayerLogIdentifier' > 437 | , m_logIdentifier(player->mediaPlayerLogIdentifier()) > | ^~~~~~~~~~~~~~~~~~~~~~~~ > /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/ > platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp: In member > function 'virtual WTFLogChannel& > WebCore::MediaPlayerPrivateGStreamer::logChannel() const': > /build/rtutils/components/desktop/webkitgtk4-dev/webkit/Source/WebCore/ > platform/graphics/gstreamer/MediaPlayerPrivateGStreamer.cpp:3844:21: error: > 'LogMedia' is not a member of 'WebCore' > 3844 | return WebCore::LogMedia; > | ^~~~~~~~ Fixed in r258691
(In reply to Philippe Normand from comment #43) > Fixed in r258691 Confirmed, builds and runs fine now. Thank you.