Bug 165533 – Memory warning logging appears to capture resident footprint, missing compress/swap.

• Component: WebCore Misc.
• Status: RESOLVED FIXED

[Keith Rollin]

In macOS/iOS, the critical pressure handler logs information about memory usage, logging footprint of the process between each step of freeing memory.

The problem is that by the look of it the logging is only reflecting the resident footprint. (The code is logging the internal value provided by the kernel – this is presumably just resident memory).

Knowing the resident number is interesting (it may indicate which tabs are touching pages), but incomplete, and means the value varies greatly throughout the process of running the low memory handler.

We should work out whether the struct passed by the kernel also provides data on the compressed/swapped footprint, and print this in addition to the resident value.

Ideally we should log –
• resident – dirty anonymous, and resident purgeable non-volatile
• swapped/compressed – dirty anonymous, and non-resident purgeable non-volatile

Clean / file-backed or purgeable volatile pages ought not be included.

[Keith Rollin]

<rdar://problem/29318410>

[Keith Rollin]

The best value for resident + swapped is vmInfo.phys_footprint.

If we're going to be printing out two values (resident memory, physical footprint memory), it no longer makes sense to use the current approach and print one of three different logging lines depending on whether memory usage went up, went down, or stayed the same after releasing memory. It seems possible for the two figures to change in different ways, leading to a combinatorial explosion of possible logging strings to print. Therefore, I'm trying the following:

                                                      Resident                             Resident + Swapped
                                     ------------- ------------- ------------- ------------- ------------- -------------
             Memory pressure relief:        Before         After         Delta        Before         After         Delta
------------------------------------ ------------- ------------- ------------- ------------- ------------- -------------
                Empty the PageCache:      51974144      51974144             0      52621312      52621312             0
   Prune MemoryCache live resources:      51974144      51974144             0      52621312      52621312             0
                 Drain CSSValuePool:      51974144      52002816         28672      52621312      52649984         28672
             Discard StyleResolvers:      52002816      52002816             0      52649984      52649984             0
      Discard all JIT-compiled code:      52002816      52359168        356352      52649984      53006336        356352
Dropping buffered data from paused :      52359168      52359168             0      53006336      53006336             0
            Purge inactive FontData:      52359168      52359168             0      53006336      53006336             0
                  Clear WidthCaches:      52359168      52359168             0      53006336      53006336             0
       Discard Selector Query Cache:      52359168      52359168             0      53006336      53006336             0
   Prune MemoryCache dead resources:      52359168      52359168             0      53006336      53006336             0
 Prune presentation attribute cache:      52359168      52359168             0      53006336      53006336             0
      Clear inline stylesheet cache:      52359168      52359168             0      53006336      53006336             0
              Purging SQLite caches:      52359168      52359168             0      53006336      53006336             0
                   Drain LayerPools:      52359168      52359168             0      53006336      53006336             0
                Drain IOSurfacePool:      52359168      52359168             0      53006336      53006336             0
     Release free FastMalloc memory:      52359168      52346880        -12288      53006336      52994048        -12288
            Purging libcache caches:      52346880      52346880             0      52994048      52994048             0

[Andreas Kling]

Side note, most deltas are going to be 0 from now on, since we no longer explicitly free malloc() and fastMalloc() memory for each ReliefLogger.
With that in mind, it might not be worth to keep this detailed logging, and instead focus on presenting a single before/after delta.

[Keith Rollin]

Created attachment 296428 [details]
Patch

[Keith Rollin]

(In reply to comment #3)
> Side note, most deltas are going to be 0 from now on, since we no longer
> explicitly free malloc() and fastMalloc() memory for each ReliefLogger.
> With that in mind, it might not be worth to keep this detailed logging, and
> instead focus on presenting a single before/after delta.

I don't think we log anything after we eventually do free that memory, either. Perhaps we should? Say, at the end of MemoryPressureHandler::releaseMemory?

[Keith Rollin]

Never mind. I see that we already have something like that with "Release free FastMalloc memory".

[Keith Rollin]

Here's an interesting one. While testing out what it would look like to generate and print a grand total, I saw this:

...
...     Drain CSSValuePool:      49803264      49836032         32768      ...
... Discard StyleResolvers:      49389568      49389568             0      ...
...

Note that there's a 432K drop between Drain CSSValuePool (After) and Discard StyleResolvers (Before). Is this just a case of "something in the background" happening to free up some memory at the same time we're doing our general cleanup?

[Andreas Kling]

(In reply to comment #7)
> Here's an interesting one. While testing out what it would look like to
> generate and print a grand total, I saw this:
> 
> ...
> ...     Drain CSSValuePool:      49803264      49836032         32768     
> ...
> ... Discard StyleResolvers:      49389568      49389568             0     
> ...
> ...
> 
> Note that there's a 432K drop between Drain CSSValuePool (After) and Discard
> StyleResolvers (Before). Is this just a case of "something in the
> background" happening to free up some memory at the same time we're doing
> our general cleanup?

Yeah that's probably the case. My guess would be bmalloc's scavenger thread that periodically returns memory to the operating system in the background.

See bmalloc::Heap::m_scavenger for implementation.

[Keith Rollin]

Created attachment 296442 [details]
Patch

[Keith Rollin]

Here's a slight update. It adds a grand total line at the bottom, which may or may not add up to the sum of the Deltas above it, depending on whether or not "something in the background" has also cleaned up. It also builds on iOS.

I'm not sure what to do about all those zeroes. What did you have in mind?

[Keith Rollin]

I guess you're saying get rid of the entire table? And just display the grand total? I'm worried that we'd be hiding something that might be valuable. Not all of the pruning is malloc or fastMalloc based, and so will generally show some memory being recovered. I think we'd like to still see that. So maybe get rid of just the rows that are malloc/fastMalloc-based? Which are those?

[Andreas Kling]

(In reply to comment #11)
> I guess you're saying get rid of the entire table? And just display the
> grand total? I'm worried that we'd be hiding something that might be
> valuable. Not all of the pruning is malloc or fastMalloc based, and so will
> generally show some memory being recovered. I think we'd like to still see
> that. So maybe get rid of just the rows that are malloc/fastMalloc-based?
> Which are those?

Regardless, these are the passes (...I think) that could free memory other than malloc/fastMalloc:

- Discard all JIT-compiled code
- Drain LayerPools
- Drain IOSurfacePool
- Dropping buffered data from paused media elements

IMO this per-pass logging has never been particularly interesting to begin with, which is a large part of the reason we want to add more logging :)

[Keith Rollin]

Based on Andreas's comments and discussion with Gavin, I've taken out all of the current ReliefLogger instances and replaced them with one that provides a grand total. The result is now just a single statement:

14:40:36.224304 -0800	Safari	Memory pressure relief: Total: res = 45481984/44896256/-585728, res+swap =  46080000/45494272/-585728

[Keith Rollin]

Created attachment 296706 [details]
Patch

[Keith Rollin]

Created attachment 296948 [details]
Patch

[Keith Rollin]

Fixes a merge conflict.

[WebKit Commit Bot]

Comment on attachment 296948 [details]
Patch

Clearing flags on attachment: 296948

Committed r209744: <http://trac.webkit.org/changeset/209744>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Csaba Osztrogonác]

(In reply to comment #17)
> Comment on attachment 296948 [details]
> Patch
> 
> Clearing flags on attachment: 296948
> 
> Committed r209744: <http://trac.webkit.org/changeset/209744>

It broke the GTK build, see build.webkit.org for details.

[Keith Rollin]

The error message is:

FAILED: /usr/lib/ccache/c++   -DBUILDING_GTK__=1 -DBUILDING_WEBKIT -DBUILDING_WITH_CMAKE=1 -DBUILDING_WebCore -DDATA_DIR=\"share\" -DGETTEXT_PACKAGE=\"WebKit2GTK-4.0\" -DHAVE_CONFIG_H=1 -DUSER_AGENT_GTK_MAJOR_VERSION=\"603\" -DUSER_AGENT_GTK_MINOR_VERSION=\"1\" -DWEBKITGTK_API_VERSION_STRING=\"4.0\" -std=c++1y -O3 -DNDEBUG -fno-exceptions -fno-strict-aliasing -fno-rtti ...<includes elided>...    -Wall -Wextra -Wcast-align -Wformat-security -Wmissing-format-attribute -Wpointer-arith -Wundef -Wwrite-strings -Wno-missing-field-initializers -fPIC -MMD -MT Source/WebCore/CMakeFiles/WebCore.dir/platform/linux/MemoryPressureHandlerLinux.cpp.o -MF Source/WebCore/CMakeFiles/WebCore.dir/platform/linux/MemoryPressureHandlerLinux.cpp.o.d -o Source/WebCore/CMakeFiles/WebCore.dir/platform/linux/MemoryPressureHandlerLinux.cpp.o -c ../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp
../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp: In member function ‘std::optional<WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage> WebCore::MemoryPressureHandler::ReliefLogger::platformMemoryUsage()’:
../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp:301:48: error: no matching function for call to ‘WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage::MemoryUsage(<brace-enclosed initializer list>)’
     return MemoryUsage {processMemoryUsage(), 0};
                                                ^
../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp:301:48: note: candidates are:
In file included from ../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp:28:0:
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note: constexpr WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage::MemoryUsage()
         struct MemoryUsage {
                ^
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note:   candidate expects 0 arguments, 2 provided
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note: constexpr WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage::MemoryUsage(const WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage&)
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note:   candidate expects 1 argument, 2 provided
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note: constexpr WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage::MemoryUsage(WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage&&)
../../Source/WebCore/platform/MemoryPressureHandler.h:117:16: note:   candidate expects 1 argument, 2 provided
../../Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp:302:1: warning: control reaches end of non-void function [-Wreturn-type]
 }
 ^
ninja: build stopped: subcommand failed.

It's not apparent to me what's wrong with the code. It's very similar to the code that compiles on cocoa:

Source/WebCore/platform/cocoa/MemoryPressureHandlerCocoa.mm
196:    return MemoryUsage {static_cast<size_t>(vmInfo.internal), static_cast<size_t>(vmInfo.phys_footprint)};

Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp
301:    return MemoryUsage {processMemoryUsage(), 0};

Perhaps the processMemoryUsage() needs to be cast to a size_t? Not likely, since it's already a size_t. Perhaps the zero needs to be cast to a size_t? Not likely because zero converts to just about anything. Perhaps MemoryUsage needs an explicit constructor? Not likely, since <http://en.cppreference.com/w/cpp/language/aggregate_initialization> says this initialization form works since C++11.

[Keith Rollin]

Reopening to attach new patch.

[Keith Rollin]

Created attachment 297025 [details]
Patch

[Keith Rollin]

This patch adds a constructor. Submitting to EWS to see if it works.

[Carlos Alberto Lopez Perez]

(In reply to comment #23)
> This patch adds a constructor. Submitting to EWS to see if it works.

There was an issue with the GTK+ EWS. Is it now working back.

The patch has just built fine on it, so please feel free to commit it (no review needed I think, is a build fix).

[Daniel Bates]

(In reply to comment #20)
> Perhaps MemoryUsage needs an explicit constructor? Not likely, since
> <http://en.cppreference.com/w/cpp/language/aggregate_initialization> says
> this initialization form works since C++11.

Notice that MemoryUsage has default initializer, we build GTK using standard c++1y, c++1y represents a revisions of the standard before C++14 and after C++11, and aggregate initialization is not allowed between [C++11, C++14] by <http://en.cppreference.com/w/cpp/language/aggregate_initialization>.

[Daniel Bates]

(In reply to comment #25)
> (In reply to comment #20)
> > Perhaps MemoryUsage needs an explicit constructor? Not likely, since
> > <http://en.cppreference.com/w/cpp/language/aggregate_initialization> says
> > this initialization form works since C++11.
> 
> Notice that MemoryUsage has default initializer, we build GTK using standard
> c++1y, c++1y represents a revisions of the standard before C++14 and after
> C++11, and aggregate initialization is not allowed between [C++11, C++14] by
> <http://en.cppreference.com/w/cpp/language/aggregate_initialization>.


*and aggregate initialization is not allowed for a struct with default member initializer between [C++11, C++14] by <http://en.cppreference.com/w/cpp/language/aggregate_initialization>.

[Daniel Bates]

Comment on attachment 297025 [details]
Patch

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

Will fix style and land this patch towards fixing the GTK build. We should consider revising this patch and the decision to have default member initializers for MemoryUsage. I take it that it makes sense to default construct MemoryUsage()?

> Source/WebCore/platform/MemoryPressureHandler.h:121
> +                , physical(physical) { }

Each of the braces should be on its own line.

[Daniel Bates]

Committed GTK build fix in <http://trac.webkit.org/changeset/209790>.

[Michael Catanzaro]

So we should probably implement this for Linux. I guess we should change WebCore::processMemoryUsage to return a WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage, using the current value for MemoryUsage.resident, then for MemoryUsage.physical... Carlos or Carlos, would ProcessMemoryStatus.size - ProcessMemoryStatus.shared be the right value...?

[Michael Catanzaro]

Or just ProcessMemoryStatus.size would probably make more sense?

[Carlos Alberto Lopez Perez]

(In reply to comment #29)
> So we should probably implement this for Linux. I guess we should change
> WebCore::processMemoryUsage to return a
> WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage, using the current
> value for MemoryUsage.resident, then for MemoryUsage.physical... Carlos or
> Carlos, would ProcessMemoryStatus.size - ProcessMemoryStatus.shared be the
> right value...?

This patch seems to be reporting as "physical" memory the phys_footprint value for the process. That means this: https://github.com/aosm/xnu/blob/master/osfmk/kern/task.c#L560

I don't think there is a direct equivalent of that on Linux, but an idea can be to report VmSize+VmSwap from /proc/self/status <-- http://man7.org/linux/man-pages/man5/proc.5.html

[Carlos Alberto Lopez Perez]

(In reply to Carlos Alberto Lopez Perez from comment #31)
> (In reply to comment #29)
> > So we should probably implement this for Linux. I guess we should change
> > WebCore::processMemoryUsage to return a
> > WebCore::MemoryPressureHandler::ReliefLogger::MemoryUsage, using the current
> > value for MemoryUsage.resident, then for MemoryUsage.physical... Carlos or
> > Carlos, would ProcessMemoryStatus.size - ProcessMemoryStatus.shared be the
> > right value...?
> 
> This patch seems to be reporting as "physical" memory the phys_footprint
> value for the process. That means this:
> https://github.com/aosm/xnu/blob/master/osfmk/kern/task.c#L560
> 
> I don't think there is a direct equivalent of that on Linux, but an idea can
> be to report VmSize+VmSwap from /proc/self/status <--
> http://man7.org/linux/man-pages/man5/proc.5.html

Yusuke implemented this on bug 171680 .

I see how Yusuke's implementation of reading anonymous page sizes is much better than just VmSize+VmSwap as I was proposing. It gives a value much more real.