Title: [285648] trunk/Source
Revision
285648
Author
n...@apple.com
Date
2021-11-11 12:40:58 -0800 (Thu, 11 Nov 2021)

Log Message

Log memory usage metadata when WebContent crosses critical or warning level memory thresholds
https://bugs.webkit.org/show_bug.cgi?id=232976

Reviewed by Darin Adler.

Source/WebCore:

WebCore::logMemoryStatistics was changed to:

 - Emit VM tag names as public strings to the log. There isn't anything privacy sensitive
   about our 256 fixed VM tags, and emitting them to the logs as as private string (as we
   were doing before) made those log lines useless.
 - Use WebCore::memoryUsageStatistics to gather memory metadata, since other WebCore
   callsites were already using that and it reduces code duplication.
 - Only log JS object type counts on internal OS builds. Previously we also logged those
   counts on public OS builds, but that was useless since all the class names were redacted
   in the log.

* page/MemoryRelease.cpp:
(WebCore::logMemoryStatistics):
(WebCore::logMemoryStatisticsReasonDescription):
(WebCore::pageCount): Deleted.
(WebCore::logMemoryStatisticsAtTimeOfDeath): Deleted.
* page/MemoryRelease.h:
* page/PerformanceLogging.cpp:
(WebCore::PerformanceLogging::memoryUsageStatistics):
(WebCore::PerformanceLogging::didReachPointOfInterest):
* page/PerformanceLogging.h:
* page/cocoa/PerformanceLoggingCocoa.mm:
(WebCore::PerformanceLogging::getPlatformMemoryUsageStatistics):

Source/WebKit:

Added callbacks to log memory usage metadata the first time a process hits these milestones:

 - exceeded inactive memory limit while active (on Mac)
 - exceeded warning process limit threshold (on other non-Mac Apple platforms)
 - exceeded critical process limit threshold (on other non-Mac Apple platforms)

The reason for this is we  receive a large number of out of memory reports with very little
info in the logs. We want to log more metadata about memory usage (similar to what we do on
Mac in `WebCore::logMemoryStatisticsAtTimeOfDeath`) to help us debug those reports.

* WebProcess/WebProcess.cpp:
(WebKit::WebProcess::initializeWebProcess):
* WebProcess/WebProcess.h:

Source/WTF:

Fixed several issues with memory usage tracking:

 - pagesPerVMTag now properly accounts for swapped-out pages in its footprint calculation,
   as footprint(1) already does.
 - displayNamePerVMTag now includes all of the most common VM tags associated with WebKit.
 - MemoryPressureHandler now knows the specific type of pressure event that occurred. This
   allows it to differentiate between the entire system being at a warning pressure level
   vs. just this process hitting its warning memory level limit.

* wtf/MemoryPressureHandler.cpp:
(WTF::MemoryPressureHandler::setMemoryPressureStatus):
(WTF::MemoryPressureHandler::memoryPressureStatusChanged):
(WTF::MemoryPressureHandler::setUnderMemoryPressure): Deleted.
* wtf/MemoryPressureHandler.h:
(WTF::MemoryPressureHandler::setMemoryPressureStatusChangedCallback):
(WTF::MemoryPressureHandler::isUnderMemoryPressure const):
* wtf/ResourceUsage.h:
* wtf/cocoa/MemoryPressureHandlerCocoa.mm:
(WTF::MemoryPressureHandler::install):
* wtf/cocoa/ResourceUsageCocoa.cpp:
(WTF::displayNameForVMTag):
(WTF::pagesPerVMTag):
* wtf/unix/MemoryPressureHandlerUnix.cpp:
(WTF::MemoryPressureHandler::triggerMemoryPressureEvent):
* wtf/win/MemoryPressureHandlerWin.cpp:
(WTF::MemoryPressureHandler::windowsMeasurementTimerFired):

Modified Paths

Diff

Modified: trunk/Source/WTF/ChangeLog (285647 => 285648)


--- trunk/Source/WTF/ChangeLog	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/ChangeLog	2021-11-11 20:40:58 UTC (rev 285648)
@@ -1,3 +1,37 @@
+2021-11-11  Ben Nham  <n...@apple.com>
+
+        Log memory usage metadata when WebContent crosses critical or warning level memory thresholds
+        https://bugs.webkit.org/show_bug.cgi?id=232976
+
+        Reviewed by Darin Adler.
+
+        Fixed several issues with memory usage tracking:
+
+         - pagesPerVMTag now properly accounts for swapped-out pages in its footprint calculation,
+           as footprint(1) already does.
+         - displayNamePerVMTag now includes all of the most common VM tags associated with WebKit.
+         - MemoryPressureHandler now knows the specific type of pressure event that occurred. This
+           allows it to differentiate between the entire system being at a warning pressure level
+           vs. just this process hitting its warning memory level limit.
+
+        * wtf/MemoryPressureHandler.cpp:
+        (WTF::MemoryPressureHandler::setMemoryPressureStatus):
+        (WTF::MemoryPressureHandler::memoryPressureStatusChanged):
+        (WTF::MemoryPressureHandler::setUnderMemoryPressure): Deleted.
+        * wtf/MemoryPressureHandler.h:
+        (WTF::MemoryPressureHandler::setMemoryPressureStatusChangedCallback):
+        (WTF::MemoryPressureHandler::isUnderMemoryPressure const):
+        * wtf/ResourceUsage.h:
+        * wtf/cocoa/MemoryPressureHandlerCocoa.mm:
+        (WTF::MemoryPressureHandler::install):
+        * wtf/cocoa/ResourceUsageCocoa.cpp:
+        (WTF::displayNameForVMTag):
+        (WTF::pagesPerVMTag):
+        * wtf/unix/MemoryPressureHandlerUnix.cpp:
+        (WTF::MemoryPressureHandler::triggerMemoryPressureEvent):
+        * wtf/win/MemoryPressureHandlerWin.cpp:
+        (WTF::MemoryPressureHandler::windowsMeasurementTimerFired):
+
 2021-11-11  Jer Noble  <jer.no...@apple.com>
 
         [iOS] Adopt -[AVAudioSession setAuditTokensForProcessAssertion:]

Modified: trunk/Source/WTF/wtf/MemoryPressureHandler.cpp (285647 => 285648)


--- trunk/Source/WTF/wtf/MemoryPressureHandler.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/MemoryPressureHandler.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -264,11 +264,12 @@
     platformReleaseMemory(critical);
 }
 
-void MemoryPressureHandler::setUnderMemoryPressure(bool underMemoryPressure)
+void MemoryPressureHandler::setMemoryPressureStatus(MemoryPressureStatus memoryPressureStatus)
 {
-    if (m_underMemoryPressure == underMemoryPressure)
+    if (m_memoryPressureStatus == memoryPressureStatus)
         return;
-    m_underMemoryPressure = underMemoryPressure;
+
+    m_memoryPressureStatus = memoryPressureStatus;
     memoryPressureStatusChanged();
 }
 
@@ -275,7 +276,7 @@
 void MemoryPressureHandler::memoryPressureStatusChanged()
 {
     if (m_memoryPressureStatusChangedCallback)
-        m_memoryPressureStatusChangedCallback(isUnderMemoryPressure());
+        m_memoryPressureStatusChangedCallback(m_memoryPressureStatus);
 }
 
 void MemoryPressureHandler::ReliefLogger::logMemoryUsageChange()

Modified: trunk/Source/WTF/wtf/MemoryPressureHandler.h (285647 => 285648)


--- trunk/Source/WTF/wtf/MemoryPressureHandler.h	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/MemoryPressureHandler.h	2021-11-11 20:40:58 UTC (rev 285648)
@@ -43,6 +43,18 @@
 
 namespace WTF {
 
+enum class MemoryPressureStatus : uint8_t {
+    Normal,
+
+    // The entire system is at a warning or critical pressure level.
+    SystemWarning,
+    SystemCritical,
+
+    // This specific process crossed a warning or critical memory usage limit.
+    ProcessLimitWarning,
+    ProcessLimitCritical
+};
+
 enum class MemoryUsagePolicy : uint8_t {
     Unrestricted, // Allocate as much as you want
     Conservative, // Maybe you don't cache every single thing
@@ -74,7 +86,7 @@
 #endif
 
     void setMemoryKillCallback(WTF::Function<void()>&& function) { m_memoryKillCallback = WTFMove(function); }
-    void setMemoryPressureStatusChangedCallback(WTF::Function<void(bool)>&& function) { m_memoryPressureStatusChangedCallback = WTFMove(function); }
+    void setMemoryPressureStatusChangedCallback(WTF::Function<void(MemoryPressureStatus)>&& function) { m_memoryPressureStatusChangedCallback = WTFMove(function); }
     void setDidExceedInactiveLimitWhileActiveCallback(WTF::Function<void()>&& function) { m_didExceedInactiveLimitWhileActiveCallback = WTFMove(function); }
 
     void setLowMemoryHandler(LowMemoryHandler&& handler)
@@ -84,7 +96,9 @@
 
     bool isUnderMemoryPressure() const
     {
-        return m_underMemoryPressure
+        auto memoryPressureStatus = m_memoryPressureStatus.load();
+        return memoryPressureStatus == MemoryPressureStatus::SystemCritical
+            || memoryPressureStatus == MemoryPressureStatus::ProcessLimitCritical
 #if PLATFORM(MAC)
             || m_memoryUsagePolicy >= MemoryUsagePolicy::Strict
 #endif
@@ -91,7 +105,7 @@
             || m_isSimulatingMemoryPressure;
     }
     bool isSimulatingMemoryPressure() const { return m_isSimulatingMemoryPressure; }
-    void setUnderMemoryPressure(bool);
+    void setMemoryPressureStatus(MemoryPressureStatus);
 
     WTF_EXPORT_PRIVATE MemoryUsagePolicy currentMemoryUsagePolicy();
 
@@ -239,7 +253,7 @@
 
     unsigned m_pageCount { 0 };
 
-    std::atomic<bool> m_underMemoryPressure { false };
+    std::atomic<MemoryPressureStatus> m_memoryPressureStatus { MemoryPressureStatus::Normal };
     bool m_installed { false };
     bool m_isSimulatingMemoryPressure { false };
     bool m_shouldLogMemoryMemoryPressureEvents { true };
@@ -251,7 +265,7 @@
 
     std::unique_ptr<RunLoop::Timer<MemoryPressureHandler>> m_measurementTimer;
     WTF::Function<void()> m_memoryKillCallback;
-    WTF::Function<void(bool)> m_memoryPressureStatusChangedCallback;
+    WTF::Function<void(MemoryPressureStatus)> m_memoryPressureStatusChangedCallback;
     WTF::Function<void()> m_didExceedInactiveLimitWhileActiveCallback;
     LowMemoryHandler m_lowMemoryHandler;
 

Modified: trunk/Source/WTF/wtf/ResourceUsage.h (285647 => 285648)


--- trunk/Source/WTF/wtf/ResourceUsage.h	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/ResourceUsage.h	2021-11-11 20:40:58 UTC (rev 285648)
@@ -33,6 +33,7 @@
 
 struct TagInfo {
     WTF_MAKE_STRUCT_FAST_ALLOCATED;
+    size_t regionCount { 0 };
     size_t dirty { 0 };
     size_t reclaimable { 0 };
     size_t reserved { 0 };

Modified: trunk/Source/WTF/wtf/cocoa/MemoryPressureHandlerCocoa.mm (285647 => 285648)


--- trunk/Source/WTF/wtf/cocoa/MemoryPressureHandlerCocoa.mm	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/cocoa/MemoryPressureHandlerCocoa.mm	2021-11-11 20:40:58 UTC (rev 285648)
@@ -78,21 +78,23 @@
             switch (status) {
             // VM pressure events.
             case DISPATCH_MEMORYPRESSURE_NORMAL:
-                setUnderMemoryPressure(false);
+                setMemoryPressureStatus(MemoryPressureStatus::Normal);
                 break;
             case DISPATCH_MEMORYPRESSURE_WARN:
-                setUnderMemoryPressure(false);
+                setMemoryPressureStatus(MemoryPressureStatus::SystemWarning);
                 respondToMemoryPressure(Critical::No);
                 break;
             case DISPATCH_MEMORYPRESSURE_CRITICAL:
-                setUnderMemoryPressure(true);
+                setMemoryPressureStatus(MemoryPressureStatus::SystemCritical);
                 respondToMemoryPressure(Critical::Yes);
                 break;
             // Process memory limit events.
             case DISPATCH_MEMORYPRESSURE_PROC_LIMIT_WARN:
+                setMemoryPressureStatus(MemoryPressureStatus::ProcessLimitWarning);
                 respondToMemoryPressure(Critical::No);
                 break;
             case DISPATCH_MEMORYPRESSURE_PROC_LIMIT_CRITICAL:
+                setMemoryPressureStatus(MemoryPressureStatus::ProcessLimitCritical);
                 respondToMemoryPressure(Critical::Yes);
                 break;
             }

Modified: trunk/Source/WTF/wtf/cocoa/ResourceUsageCocoa.cpp (285647 => 285648)


--- trunk/Source/WTF/wtf/cocoa/ResourceUsageCocoa.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/cocoa/ResourceUsageCocoa.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -72,28 +72,32 @@
 const char* displayNameForVMTag(unsigned tag)
 {
     switch (tag) {
+    case VM_MEMORY_CGIMAGE: return "CG image";
+    case VM_MEMORY_COREGRAPHICS_DATA: return "CG raster data";
+    case VM_MEMORY_CORESERVICES: return "CoreServices";
+    case VM_MEMORY_DYLIB: return "dylib";
+    case VM_MEMORY_FOUNDATION: return "Foundation";
+    case VM_MEMORY_IMAGEIO: return "ImageIO";
+    case VM_MEMORY_IOACCELERATOR: return "IOAccelerator";
+    case VM_MEMORY_IOSURFACE: return "IOSurface";
     case VM_MEMORY_IOKIT: return "IOKit";
-    case VM_MEMORY_LAYERKIT: return "CoreAnimation";
-    case VM_MEMORY_IMAGEIO: return "ImageIO";
-    case VM_MEMORY_CGIMAGE: return "CG image";
     case VM_MEMORY_JAVASCRIPT_CORE: return "Gigacage";
     case VM_MEMORY_JAVASCRIPT_JIT_EXECUTABLE_ALLOCATOR: return "JSC JIT";
     case VM_MEMORY_JAVASCRIPT_JIT_REGISTER_FILE: return "IsoHeap";
+    case VM_MEMORY_LAYERKIT: return "CoreAnimation";
+    case VM_MEMORY_LIBDISPATCH: return "libdispatch";
     case VM_MEMORY_MALLOC: return "malloc";
     case VM_MEMORY_MALLOC_HUGE: return "malloc (huge)";
     case VM_MEMORY_MALLOC_LARGE: return "malloc (large)";
+    case VM_MEMORY_MALLOC_MEDIUM: return "malloc (medium)";
+    case VM_MEMORY_MALLOC_NANO: return "malloc (nano)";
     case VM_MEMORY_MALLOC_SMALL: return "malloc (small)";
     case VM_MEMORY_MALLOC_TINY: return "malloc (tiny)";
-    case VM_MEMORY_MALLOC_NANO: return "malloc (nano)";
+    case VM_MEMORY_OS_ALLOC_ONCE: return "os_alloc_once";
+    case VM_MEMORY_SQLITE: return "SQLite";
+    case VM_MEMORY_STACK: return "Stack";
     case VM_MEMORY_TCMALLOC: return "bmalloc";
-    case VM_MEMORY_FOUNDATION: return "Foundation";
-    case VM_MEMORY_STACK: return "Stack";
-    case VM_MEMORY_SQLITE: return "SQLite";
     case VM_MEMORY_UNSHARED_PMAP: return "pmap (unshared)";
-    case VM_MEMORY_DYLIB: return "dylib";
-    case VM_MEMORY_CORESERVICES: return "CoreServices";
-    case VM_MEMORY_OS_ALLOC_ONCE: return "os_alloc_once";
-    case VM_MEMORY_LIBDISPATCH: return "libdispatch";
     default: return nullptr;
     }
 }
@@ -115,6 +119,8 @@
         if (kr != KERN_SUCCESS)
             break;
 
+        tags[info.user_tag].regionCount++;
+
         tags[info.user_tag].reserved += size / vmPageSize();
 
         if (purgeableState == VM_PURGABLE_VOLATILE) {
@@ -127,12 +133,13 @@
             continue;
         }
 
+        // This calculates the footprint of a VM region in a manner similar to what footprint(1) does in the legacy --vmObjectDirty mode.
         bool anonymous = !info.external_pager;
         if (anonymous) {
-            tags[info.user_tag].dirty += info.pages_resident - info.pages_reusable;
+            tags[info.user_tag].dirty += info.pages_resident - info.pages_reusable + info.pages_swapped_out;
             tags[info.user_tag].reclaimable += info.pages_reusable;
         } else
-            tags[info.user_tag].dirty += info.pages_dirtied;
+            tags[info.user_tag].dirty += info.pages_dirtied + info.pages_swapped_out;
     }
 
     return tags;

Modified: trunk/Source/WTF/wtf/unix/MemoryPressureHandlerUnix.cpp (285647 => 285648)


--- trunk/Source/WTF/wtf/unix/MemoryPressureHandlerUnix.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/unix/MemoryPressureHandlerUnix.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -66,7 +66,7 @@
     if (ReliefLogger::loggingEnabled())
         LOG(MemoryPressure, "Got memory pressure notification (%s)", isCritical ? "critical" : "non-critical");
 
-    setUnderMemoryPressure(true);
+    setMemoryPressureStatus(MemoryPressureStatus::SystemCritical);
 
     ensureOnMainThread([this, isCritical] {
         respondToMemoryPressure(isCritical ? Critical::Yes : Critical::No);
@@ -75,7 +75,7 @@
     if (ReliefLogger::loggingEnabled() && isUnderMemoryPressure())
         LOG(MemoryPressure, "System is no longer under memory pressure.");
 
-    setUnderMemoryPressure(false);
+    setMemoryPressureStatus(MemoryPressureStatus::Normal);
 }
 
 void MemoryPressureHandler::install()

Modified: trunk/Source/WTF/wtf/win/MemoryPressureHandlerWin.cpp (285647 => 285648)


--- trunk/Source/WTF/wtf/win/MemoryPressureHandlerWin.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WTF/wtf/win/MemoryPressureHandlerWin.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -38,12 +38,12 @@
 
 void MemoryPressureHandler::windowsMeasurementTimerFired()
 {
-    setUnderMemoryPressure(false);
+    setMemoryPressureStatus(MemoryPressureStatus::Normal);
 
     BOOL memoryLow;
 
     if (QueryMemoryResourceNotification(m_lowMemoryHandle.get(), &memoryLow) && memoryLow) {
-        setUnderMemoryPressure(true);
+        setMemoryPressureStatus(MemoryPressureStatus::SystemCritical);
         releaseMemory(Critical::Yes);
         return;
     }
@@ -60,7 +60,7 @@
     const int maxMemoryUsageBytes = 0.9 * 1024 * 1024 * 1024;
 
     if (counters.PrivateUsage > maxMemoryUsageBytes) {
-        setUnderMemoryPressure(true);
+        setMemoryPressureStatus(MemoryPressureStatus::ProcessLimitCritical);
         releaseMemory(Critical::Yes);
     }
 #endif

Modified: trunk/Source/WebCore/ChangeLog (285647 => 285648)


--- trunk/Source/WebCore/ChangeLog	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/ChangeLog	2021-11-11 20:40:58 UTC (rev 285648)
@@ -1,3 +1,34 @@
+2021-11-11  Ben Nham  <n...@apple.com>
+
+        Log memory usage metadata when WebContent crosses critical or warning level memory thresholds
+        https://bugs.webkit.org/show_bug.cgi?id=232976
+
+        Reviewed by Darin Adler.
+
+        WebCore::logMemoryStatistics was changed to:
+
+         - Emit VM tag names as public strings to the log. There isn't anything privacy sensitive
+           about our 256 fixed VM tags, and emitting them to the logs as as private string (as we
+           were doing before) made those log lines useless.
+         - Use WebCore::memoryUsageStatistics to gather memory metadata, since other WebCore
+           callsites were already using that and it reduces code duplication.
+         - Only log JS object type counts on internal OS builds. Previously we also logged those
+           counts on public OS builds, but that was useless since all the class names were redacted
+           in the log.
+
+        * page/MemoryRelease.cpp:
+        (WebCore::logMemoryStatistics):
+        (WebCore::logMemoryStatisticsReasonDescription):
+        (WebCore::pageCount): Deleted.
+        (WebCore::logMemoryStatisticsAtTimeOfDeath): Deleted.
+        * page/MemoryRelease.h:
+        * page/PerformanceLogging.cpp:
+        (WebCore::PerformanceLogging::memoryUsageStatistics):
+        (WebCore::PerformanceLogging::didReachPointOfInterest):
+        * page/PerformanceLogging.h:
+        * page/cocoa/PerformanceLoggingCocoa.mm:
+        (WebCore::PerformanceLogging::getPlatformMemoryUsageStatistics):
+
 2021-11-11  Jer Noble  <jer.no...@apple.com>
 
         [iOS] Adopt -[AVAudioSession setAuditTokensForProcessAssertion:]

Modified: trunk/Source/WebCore/page/MemoryRelease.cpp (285647 => 285648)


--- trunk/Source/WebCore/page/MemoryRelease.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/page/MemoryRelease.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -46,6 +46,7 @@
 #include "Logging.h"
 #include "MemoryCache.h"
 #include "Page.h"
+#include "PerformanceLogging.h"
 #include "RenderTheme.h"
 #include "ScrollingThread.h"
 #include "StyleScope.h"
@@ -60,6 +61,7 @@
 
 #if PLATFORM(COCOA)
 #include "ResourceUsageThread.h"
+#include <wtf/spi/darwin/OSVariantSPI.h>
 #endif
 
 namespace WebCore {
@@ -175,26 +177,38 @@
     WTF::releaseFastMallocFreeMemory();
 }
 
-#if !RELEASE_LOG_DISABLED
-static unsigned pageCount()
+#if RELEASE_LOG_DISABLED
+void logMemoryStatistics(LogMemoryStatisticsReason) { }
+#else
+static const char* logMemoryStatisticsReasonDescription(LogMemoryStatisticsReason reason)
 {
-    unsigned count = 0;
-    Page::forEachPage([&] (Page& page) {
-        if (!page.isUtilityPage())
-            ++count;
-    });
-    return count;
+    switch (reason) {
+    case LogMemoryStatisticsReason::DebugNotification:
+        return "debug notification";
+    case LogMemoryStatisticsReason::WarningMemoryPressureNotification:
+        return "warning memory pressure notification";
+    case LogMemoryStatisticsReason::CriticalMemoryPressureNotification:
+        return "critical memory pressure notification";
+    case LogMemoryStatisticsReason::OutOfMemoryDeath:
+        return "out of memory death";
+    };
+    RELEASE_ASSERT_NOT_REACHED();
 }
-#endif
 
-void logMemoryStatisticsAtTimeOfDeath()
+void logMemoryStatistics(LogMemoryStatisticsReason reason)
 {
-#if !RELEASE_LOG_DISABLED
+    const char* description = logMemoryStatisticsReasonDescription(reason);
+
+    RELEASE_LOG(MemoryPressure, "WebKit memory usage statistics at time of %" PUBLIC_LOG_STRING ":", description);
+    auto stats = PerformanceLogging::memoryUsageStatistics(ShouldIncludeExpensiveComputations::Yes);
+    for (auto& [key, val] : stats)
+        RELEASE_LOG(MemoryPressure, "%" PUBLIC_LOG_STRING ": %zu", key, val);
+
 #if PLATFORM(COCOA)
     auto pageSize = vmPageSize();
     auto pages = pagesPerVMTag();
 
-    RELEASE_LOG(MemoryPressure, "Dirty memory per VM tag at time of death:");
+    RELEASE_LOG(MemoryPressure, "Dirty memory per VM tag at time of %" PUBLIC_LOG_STRING ":", description);
     for (unsigned i = 0; i < 256; ++i) {
         size_t dirty = pages[i].dirty * pageSize;
         if (!dirty)
@@ -202,28 +216,22 @@
         String tagName = displayNameForVMTag(i);
         if (!tagName)
             tagName = makeString("Tag ", i);
-        RELEASE_LOG(MemoryPressure, "%16s: %lu MB", tagName.latin1().data(), dirty / MB);
+        RELEASE_LOG(MemoryPressure, "  %" PUBLIC_LOG_STRING ": %lu MB in %zu regions", tagName.latin1().data(), dirty / MB, pages[i].regionCount);
     }
+
+    bool shouldLogJavaScriptObjectCounts = os_variant_allows_internal_security_policies("com.apple.WebKit");
+    if (!shouldLogJavaScriptObjectCounts)
+        return;
 #endif
 
     auto& vm = commonVM();
     JSC::JSLockHolder locker(vm);
-    RELEASE_LOG(MemoryPressure, "Memory usage statistics at time of death:");
-    RELEASE_LOG(MemoryPressure, "GC heap size: %zu", vm.heap.size());
-    RELEASE_LOG(MemoryPressure, "GC heap extra memory size: %zu", vm.heap.extraMemorySize());
-#if ENABLE(RESOURCE_USAGE)
-    RELEASE_LOG(MemoryPressure, "GC heap external memory: %zu", vm.heap.externalMemorySize());
-#endif
-    RELEASE_LOG(MemoryPressure, "Global object count: %zu", vm.heap.globalObjectCount());
-
-    RELEASE_LOG(MemoryPressure, "Page count: %u", pageCount());
-    RELEASE_LOG(MemoryPressure, "Document count: %u", Document::allDocuments().size());
-    RELEASE_LOG(MemoryPressure, "Live _javascript_ objects:");
+    RELEASE_LOG(MemoryPressure, "Live _javascript_ objects at time of %" PUBLIC_LOG_STRING ":", description);
     auto typeCounts = vm.heap.objectTypeCounts();
     for (auto& it : *typeCounts)
-        RELEASE_LOG(MemoryPressure, "  %s: %d", it.key, it.value);
+        RELEASE_LOG(MemoryPressure, "  %" PUBLIC_LOG_STRING ": %d", it.key, it.value);
+}
 #endif
-}
 
 #if !PLATFORM(COCOA)
 void platformReleaseMemory(Critical) { }

Modified: trunk/Source/WebCore/page/MemoryRelease.h (285647 => 285648)


--- trunk/Source/WebCore/page/MemoryRelease.h	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/page/MemoryRelease.h	2021-11-11 20:40:58 UTC (rev 285648)
@@ -31,6 +31,12 @@
 
 enum class MaintainBackForwardCache : bool { No, Yes };
 enum class MaintainMemoryCache : bool { No, Yes };
+enum class LogMemoryStatisticsReason : uint8_t {
+    DebugNotification,
+    WarningMemoryPressureNotification,
+    CriticalMemoryPressureNotification,
+    OutOfMemoryDeath
+};
 
 WEBCORE_EXPORT void releaseMemory(Critical, Synchronous, MaintainBackForwardCache = MaintainBackForwardCache::No, MaintainMemoryCache = MaintainMemoryCache::No);
 void platformReleaseMemory(Critical);
@@ -38,6 +44,6 @@
 void platformReleaseGraphicsMemory(Critical);
 void jettisonExpensiveObjectsOnTopLevelNavigation();
 WEBCORE_EXPORT void registerMemoryReleaseNotifyCallbacks();
-WEBCORE_EXPORT void logMemoryStatisticsAtTimeOfDeath();
+WEBCORE_EXPORT void logMemoryStatistics(LogMemoryStatisticsReason);
 
 } // namespace WebCore

Modified: trunk/Source/WebCore/page/PerformanceLogging.cpp (285647 => 285648)


--- trunk/Source/WebCore/page/PerformanceLogging.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/page/PerformanceLogging.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -56,19 +56,19 @@
 HashMap<const char*, size_t> PerformanceLogging::memoryUsageStatistics(ShouldIncludeExpensiveComputations includeExpensive)
 {
     HashMap<const char*, size_t> stats;
+    stats.reserveInitialCapacity(32);
 
+    stats.add("page_count", Page::nonUtilityPageCount());
+    stats.add("backforward_cache_page_count", BackForwardCache::singleton().pageCount());
+    stats.add("document_count", Document::allDocuments().size());
+
     auto& vm = commonVM();
     JSC::JSLockHolder locker(vm);
-    stats.add("_javascript__gc_heap_capacity", vm.heap.capacity());
-    stats.add("_javascript__gc_heap_extra_memory_size", vm.heap.extraMemorySize());
+    stats.add("_javascript__gc_heap_capacity_mb", vm.heap.capacity() >> 20);
+    stats.add("_javascript__gc_heap_extra_memory_size_mb", vm.heap.extraMemorySize() >> 20);
 
-    auto& backForwardCache = BackForwardCache::singleton();
-    stats.add("backforward_cache_page_count", backForwardCache.pageCount());
-
-    stats.add("document_count", Document::allDocuments().size());
-
     if (includeExpensive == ShouldIncludeExpensiveComputations::Yes) {
-        stats.add("_javascript__gc_heap_size", vm.heap.size());
+        stats.add("_javascript__gc_heap_size_mb", vm.heap.size() >> 20);
         stats.add("_javascript__gc_object_count", vm.heap.objectCount());
         stats.add("_javascript__gc_protected_object_count", vm.heap.protectedObjectCount());
         stats.add("_javascript__gc_global_object_count", vm.heap.globalObjectCount());
@@ -75,6 +75,8 @@
         stats.add("_javascript__gc_protected_global_object_count", vm.heap.protectedGlobalObjectCount());
     }
 
+    getPlatformMemoryUsageStatistics(stats);
+
     return stats;
 }
 
@@ -98,11 +100,8 @@
     if (m_page.mainFrame().loader().client().isEmptyFrameLoaderClient())
         return;
 
-    auto stats = memoryUsageStatistics(ShouldIncludeExpensiveComputations::No);
-    getPlatformMemoryUsageStatistics(stats);
-
     RELEASE_LOG(PerformanceLogging, "Memory usage info dump at %s:", toString(poi));
-    for (auto& it : stats)
+    for (auto& it : memoryUsageStatistics(ShouldIncludeExpensiveComputations::No))
         RELEASE_LOG(PerformanceLogging, "  %s: %zu", it.key, it.value);
 #endif
 }

Modified: trunk/Source/WebCore/page/PerformanceLogging.h (285647 => 285648)


--- trunk/Source/WebCore/page/PerformanceLogging.h	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/page/PerformanceLogging.h	2021-11-11 20:40:58 UTC (rev 285648)
@@ -32,7 +32,7 @@
 
 class Page;
 
-enum class ShouldIncludeExpensiveComputations { No, Yes };
+enum class ShouldIncludeExpensiveComputations : bool { No, Yes };
 
 class PerformanceLogging {
     WTF_MAKE_FAST_ALLOCATED;

Modified: trunk/Source/WebCore/page/cocoa/PerformanceLoggingCocoa.mm (285647 => 285648)


--- trunk/Source/WebCore/page/cocoa/PerformanceLoggingCocoa.mm	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebCore/page/cocoa/PerformanceLoggingCocoa.mm	2021-11-11 20:40:58 UTC (rev 285648)
@@ -48,11 +48,11 @@
     kern_return_t err = task_info(mach_task_self(), TASK_VM_INFO, (task_info_t) &vmInfo, &count);
     if (err != KERN_SUCCESS)
         return;
-    stats.add("internal", static_cast<size_t>(vmInfo.internal));
-    stats.add("compressed", static_cast<size_t>(vmInfo.compressed));
-    stats.add("phys_footprint", static_cast<size_t>(vmInfo.phys_footprint));
-    stats.add("resident_size", static_cast<size_t>(vmInfo.resident_size));
-    stats.add("virtual_size", static_cast<size_t>(vmInfo.virtual_size));
+    stats.add("internal_mb", static_cast<size_t>(vmInfo.internal >> 20));
+    stats.add("compressed_mb", static_cast<size_t>(vmInfo.compressed >> 20));
+    stats.add("phys_footprint_mb", static_cast<size_t>(vmInfo.phys_footprint >> 20));
+    stats.add("resident_size_mb", static_cast<size_t>(vmInfo.resident_size >> 20));
+    stats.add("virtual_size_mb", static_cast<size_t>(vmInfo.virtual_size >> 20));
 }
 
 }

Modified: trunk/Source/WebKit/ChangeLog (285647 => 285648)


--- trunk/Source/WebKit/ChangeLog	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebKit/ChangeLog	2021-11-11 20:40:58 UTC (rev 285648)
@@ -1,3 +1,24 @@
+2021-11-11  Ben Nham  <n...@apple.com>
+
+        Log memory usage metadata when WebContent crosses critical or warning level memory thresholds
+        https://bugs.webkit.org/show_bug.cgi?id=232976
+
+        Reviewed by Darin Adler.
+
+        Added callbacks to log memory usage metadata the first time a process hits these milestones:
+
+         - exceeded inactive memory limit while active (on Mac)
+         - exceeded warning process limit threshold (on other non-Mac Apple platforms)
+         - exceeded critical process limit threshold (on other non-Mac Apple platforms)
+
+        The reason for this is we  receive a large number of out of memory reports with very little
+        info in the logs. We want to log more metadata about memory usage (similar to what we do on
+        Mac in `WebCore::logMemoryStatisticsAtTimeOfDeath`) to help us debug those reports.
+
+        * WebProcess/WebProcess.cpp:
+        (WebKit::WebProcess::initializeWebProcess):
+        * WebProcess/WebProcess.h:
+
 2021-11-11  Rachel Ginsberg  <rginsb...@apple.com>
 
         Add support in WebCore for web app manifest icons

Modified: trunk/Source/WebKit/WebProcess/WebProcess.cpp (285647 => 285648)


--- trunk/Source/WebKit/WebProcess/WebProcess.cpp	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebKit/WebProcess/WebProcess.cpp	2021-11-11 20:40:58 UTC (rev 285648)
@@ -135,6 +135,7 @@
 #include <WebCore/ServiceWorkerContextData.h>
 #include <WebCore/Settings.h>
 #include <WebCore/UserGestureIndicator.h>
+#include <pal/Logging.h>
 #include <wtf/Algorithms.h>
 #include <wtf/CallbackAggregator.h>
 #include <wtf/Language.h>
@@ -376,6 +377,14 @@
     m_webConnection = WebConnectionToUIProcess::create(this);
 }
 
+static void scheduleLogMemoryStatistics(LogMemoryStatisticsReason reason)
+{
+    // Log stats in the next turn of the run loop so that it runs after the low memory handler.
+    RunLoop::main().dispatch([reason] {
+        WebCore::logMemoryStatistics(reason);
+    });
+}
+
 void WebProcess::initializeWebProcess(WebProcessCreationParameters&& parameters)
 {    
     TraceScope traceScope(InitializeWebProcessStart, InitializeWebProcessEnd);
@@ -429,7 +438,7 @@
 #if ENABLE(PERIODIC_MEMORY_MONITOR)
         memoryPressureHandler.setShouldUsePeriodicMemoryMonitor(true);
         memoryPressureHandler.setMemoryKillCallback([this] () {
-            WebCore::logMemoryStatisticsAtTimeOfDeath();
+            WebCore::logMemoryStatistics(LogMemoryStatisticsReason::OutOfMemoryDeath);
             if (MemoryPressureHandler::singleton().processState() == WebsamProcessState::Active)
                 parentProcessConnection()->send(Messages::WebProcessProxy::DidExceedActiveMemoryLimit(), 0);
             else
@@ -437,13 +446,30 @@
         });
         memoryPressureHandler.setDidExceedInactiveLimitWhileActiveCallback([this] () {
             parentProcessConnection()->send(Messages::WebProcessProxy::DidExceedInactiveMemoryLimitWhileActive(), 0);
+
+            if (!m_loggedProcessLimitCriticalMemoryStatistics) {
+                m_loggedProcessLimitCriticalMemoryStatistics = true;
+                scheduleLogMemoryStatistics(LogMemoryStatisticsReason::CriticalMemoryPressureNotification);
+            }
         });
 #endif
-        memoryPressureHandler.setMemoryPressureStatusChangedCallback([this](bool isUnderMemoryPressure) {
+        memoryPressureHandler.setMemoryPressureStatusChangedCallback([this](WTF::MemoryPressureStatus memoryPressureStatus) {
             if (parentProcessConnection())
-                parentProcessConnection()->send(Messages::WebProcessProxy::MemoryPressureStatusChanged(isUnderMemoryPressure), 0);
+                parentProcessConnection()->send(Messages::WebProcessProxy::MemoryPressureStatusChanged(MemoryPressureHandler::singleton().isUnderMemoryPressure()), 0);
+
+            if (memoryPressureStatus == WTF::MemoryPressureStatus::ProcessLimitWarning && !m_loggedProcessLimitWarningMemoryStatistics) {
+                m_loggedProcessLimitWarningMemoryStatistics = true;
+                scheduleLogMemoryStatistics(LogMemoryStatisticsReason::WarningMemoryPressureNotification);
+            } else if (memoryPressureStatus == WTF::MemoryPressureStatus::ProcessLimitCritical && !m_loggedProcessLimitCriticalMemoryStatistics) {
+                m_loggedProcessLimitCriticalMemoryStatistics = true;
+                scheduleLogMemoryStatistics(LogMemoryStatisticsReason::CriticalMemoryPressureNotification);
+            }
         });
         memoryPressureHandler.install();
+
+        PAL::registerNotifyCallback("com.apple.WebKit.logMemStats", [] {
+            WebCore::logMemoryStatistics(LogMemoryStatisticsReason::DebugNotification);
+        });
     }
 
     SandboxExtension::consumePermanently(parameters.additionalSandboxExtensionHandles);

Modified: trunk/Source/WebKit/WebProcess/WebProcess.h (285647 => 285648)


--- trunk/Source/WebKit/WebProcess/WebProcess.h	2021-11-11 20:39:35 UTC (rev 285647)
+++ trunk/Source/WebKit/WebProcess/WebProcess.h	2021-11-11 20:40:58 UTC (rev 285648)
@@ -709,6 +709,8 @@
 #endif
 
     bool m_suppressMemoryPressureHandler { false };
+    bool m_loggedProcessLimitWarningMemoryStatistics { false };
+    bool m_loggedProcessLimitCriticalMemoryStatistics { false };
 #if PLATFORM(MAC)
     std::unique_ptr<WebCore::CPUMonitor> m_cpuMonitor;
     std::optional<double> m_cpuLimit;
_______________________________________________
webkit-changes mailing list
webkit-changes@lists.webkit.org
https://lists.webkit.org/mailman/listinfo/webkit-changes

Reply via email to