Bug 165533 - Memory warning logging appears to capture resident footprint, missing compress/swap.
Summary: Memory warning logging appears to capture resident footprint, missing compres...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: WebCore Misc. (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Keith Rollin
URL:
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2016-12-07 10:46 PST by Keith Rollin
Modified: 2017-05-04 13:07 PDT (History)
13 users (show)

See Also:


Attachments
Patch (10.31 KB, patch)
2016-12-07 15:21 PST, Keith Rollin
no flags Details | Formatted Diff | Diff
Patch (10.38 KB, patch)
2016-12-07 16:57 PST, Keith Rollin
no flags Details | Formatted Diff | Diff
Patch (16.76 KB, patch)
2016-12-09 14:49 PST, Keith Rollin
no flags Details | Formatted Diff | Diff
Patch (16.86 KB, patch)
2016-12-12 13:40 PST, Keith Rollin
no flags Details | Formatted Diff | Diff
Patch (1.49 KB, patch)
2016-12-13 10:51 PST, Keith Rollin
dbates: review+
Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Keith Rollin 2016-12-07 10:46:28 PST
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.
Comment 1 Keith Rollin 2016-12-07 10:46:45 PST
<rdar://problem/29318410>
Comment 2 Keith Rollin 2016-12-07 15:10:32 PST
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
Comment 3 Andreas Kling 2016-12-07 15:15:35 PST
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.
Comment 4 Keith Rollin 2016-12-07 15:21:12 PST
Created attachment 296428 [details]
Patch
Comment 5 Keith Rollin 2016-12-07 15:24:38 PST
(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?
Comment 6 Keith Rollin 2016-12-07 15:57:45 PST
Never mind. I see that we already have something like that with "Release free FastMalloc memory".
Comment 7 Keith Rollin 2016-12-07 16:14:47 PST
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?
Comment 8 Andreas Kling 2016-12-07 16:32:46 PST
(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.
Comment 9 Keith Rollin 2016-12-07 16:57:14 PST
Created attachment 296442 [details]
Patch
Comment 10 Keith Rollin 2016-12-07 16:58:43 PST
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?
Comment 11 Keith Rollin 2016-12-07 17:04:28 PST
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?
Comment 12 Andreas Kling 2016-12-08 03:32:27 PST
(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 :)
Comment 13 Keith Rollin 2016-12-09 14:43:30 PST
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
Comment 14 Keith Rollin 2016-12-09 14:49:41 PST
Created attachment 296706 [details]
Patch
Comment 15 Keith Rollin 2016-12-12 13:40:07 PST
Created attachment 296948 [details]
Patch
Comment 16 Keith Rollin 2016-12-12 13:40:44 PST
Fixes a merge conflict.
Comment 17 WebKit Commit Bot 2016-12-12 16:28:51 PST
Comment on attachment 296948 [details]
Patch

Clearing flags on attachment: 296948

Committed r209744: <http://trac.webkit.org/changeset/209744>
Comment 18 WebKit Commit Bot 2016-12-12 16:28:57 PST
All reviewed patches have been landed.  Closing bug.
Comment 19 Csaba Osztrogonác 2016-12-12 23:00:32 PST
(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.
Comment 20 Keith Rollin 2016-12-13 10:30:26 PST
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.
Comment 21 Keith Rollin 2016-12-13 10:51:05 PST
Reopening to attach new patch.
Comment 22 Keith Rollin 2016-12-13 10:51:07 PST
Created attachment 297025 [details]
Patch
Comment 23 Keith Rollin 2016-12-13 10:52:07 PST
This patch adds a constructor. Submitting to EWS to see if it works.
Comment 24 Carlos Alberto Lopez Perez 2016-12-13 21:47:33 PST
(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).
Comment 25 Daniel Bates 2016-12-13 22:01:01 PST
(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>.
Comment 26 Daniel Bates 2016-12-13 22:02:48 PST
(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>.
Comment 27 Daniel Bates 2016-12-13 22:08:20 PST
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.
Comment 28 Daniel Bates 2016-12-13 22:10:44 PST
Committed GTK build fix in <http://trac.webkit.org/changeset/209790>.
Comment 29 Michael Catanzaro 2016-12-19 20:15:39 PST
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...?
Comment 30 Michael Catanzaro 2016-12-19 20:16:35 PST
Or just ProcessMemoryStatus.size would probably make more sense?
Comment 31 Carlos Alberto Lopez Perez 2016-12-21 20:32:43 PST
(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
Comment 32 Carlos Alberto Lopez Perez 2017-05-04 13:07:36 PDT
(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.