New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 826913 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Apr 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 1
Type: Bug
Hotlist-MemoryInfra

Blocking:
issue 841951



Sign in to add a comment

Browser process hang in memory_instrumentation::OSMetrics::GetProcessMemoryMaps

Project Member Reported by kbr@chromium.org, Mar 28 2018

Issue description

Google Chrome	67.0.3377.0 (Official Build) canary (64-bit)
Revision	d77b019f5aa49e13a58521f3b1e3604bd391be53-refs/heads/master@{#544610}
OS: macOS 10.13.3

What steps will reproduce the problem?
(1) Use browser normally, including Google Docs in a tab

What is the expected result?

Expect browser to work smoothly.


What happens instead?

Frequent browser pauses and occasional complete hangs. See attached symbolized sample.

The browser recovered some time after gathering this sample and after switching applications.


Call graph:
    520 Thread_5424439   DispatchQueue_1: com.apple.main-thread  (serial)
    + 520 start  (in libdyld.dylib) + 1  [0x7fff5b26c115]
    +   520 main  (in Google Chrome Canary) + 404  [0x10a70ddd4]
    +     520 ChromeMain  (in Google Chrome Framework) + 179  [chrome_main.cc:0]
    +       520 content::ContentMain(content::ContentMainParams const&)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x1cf0844  [content_main.cc:19]
    +         520 service_manager::Main(service_manager::MainParams const&)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34edfd0  [main.cc:453]
    +           520 content::ContentMainRunnerImpl::Run()  (in Google Chrome Framework)  load address 0x10a75b000 + 0x1cf12f9  [content_main_runner.cc:703]
    +             520 content::BrowserMain(content::MainFunctionParams const&)  (in Google Chrome Framework)  load address 0x10a75b000 + 0xa26c4b  [browser_main.cc:46]
    +               520 content::BrowserMainRunnerImpl::Run()  (in Google Chrome Framework)  load address 0x10a75b000 + 0xa2c8d2  [memory:2615]
    +                 520 content::BrowserMainLoop::RunMainMessageLoopParts()  (in Google Chrome Framework)  load address 0x10a75b000 + 0xa2a2a4  [browser_main_loop.cc:1059]
    +                   520 ChromeBrowserMainParts::MainMessageLoopRun(int*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x1d3f328  [chrome_browser_main.cc:2174]
    +                     520 <name omitted>  (in Google Chrome Framework)  load address 0x10a75b000 + 0x2120995  [run_loop.cc:136]
    +                       520 base::MessagePumpCFRunLoopBase::Run(base::MessagePump::Delegate*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fc43e  [message_pump_mac.mm:311]
    +                         520 base::MessagePumpNSApplication::DoRun(base::MessagePump::Delegate*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fd8bc  [message_pump_mac.mm:831]
    +                           520 -[NSApplication run]  (in AppKit) + 764  [0x7fff30f30d6d]
    +                             520 -[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]  (in Google Chrome Framework)  load address 0x10a75b000 + 0x1d39044  [chrome_browser_application_mac.mm:182]
    +                               520 base::mac::CallWithEHFrame(void () block_pointer)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20eea9a  []
    +                                 520 __71-[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]_block_invoke  (in Google Chrome Framework)  load address 0x10a75b000 + 0x1d39100  [chrome_browser_application_mac.mm:177]
    +                                   520 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]  (in AppKit) + 3044  [0x7fff316d1b4c]
    +                                     520 _DPSNextEvent  (in AppKit) + 2085  [0x7fff30f3bf5f]
    +                                       520 _BlockUntilNextEventMatchingListInModeWithFilter  (in HIToolbox) + 64  [0x7fff32c70914]
    +                                         520 ReceiveNextEventCommon  (in HIToolbox) + 613  [0x7fff32c70b96]
    +                                           520 RunCurrentEventLoopInMode  (in HIToolbox) + 286  [0x7fff32c70e26]
    +                                             520 CFRunLoopRunSpecific  (in CoreFoundation) + 483  [0x7fff33958f43]
    +                                               520 __CFRunLoopRun  (in CoreFoundation) + 1293  [0x7fff339596dd]
    +                                                 520 __CFRunLoopDoSources0  (in CoreFoundation) + 208  [0x7fff3395a260]
    +                                                   520 __CFRunLoopDoSource0  (in CoreFoundation) + 108  [0x7fff33a310ac]
    +                                                     520 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__  (in CoreFoundation) + 17  [0x7fff33977721]
    +                                                       520 base::MessagePumpCFRunLoopBase::RunWorkSource(void*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fc91f  [message_pump_mac.mm:441]
    +                                                         520 base::mac::CallWithEHFrame(void () block_pointer)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20eea9a  []
    +                                                           520 base::MessagePumpCFRunLoopBase::RunWork()  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fcffa  [message_pump_mac.mm:462]
    +                                                             520 base::MessageLoop::DoWork()  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fb048  [message_loop.cc:447]
    +                                                               520 base::MessageLoop::RunTask(base::PendingTask*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20fab64  [vector:639]
    +                                                                 520 base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x20d61a8  [callback_forward.h:11]
    +                                                                   520 mojo::SimpleWatcher::OnHandleReady(int, unsigned int, mojo::HandleSignalsState const&)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21cfcb8  [weak_ptr.h:243]
    +                                                                     520 mojo::Connector::ReadAllAvailableMessages()  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21bedd1  [connector.cc:472]
    +                                                                       520 mojo::Connector::ReadSingleMessage(unsigned int*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21be78b  [connector.cc:443]
    +                                                                         520 mojo::internal::MultiplexRouter::Accept(mojo::Message*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21c4544  [multiplex_router.cc:608]
    +                                                                           520 mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21c4d01  [multiplex_router.cc:0]
    +                                                                             520 mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x21c0598  [interface_endpoint_client.cc:394]
    +                                                                               520 memory_instrumentation::mojom::ClientProcessStub<mojo::RawPtrImplRefTraits<memory_instrumentation::mojom::ClientProcess> >::AcceptWithResponder(mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d0c56  [memory_instrumentation.mojom.h:476]
    +                                                                                 520 memory_instrumentation::mojom::ClientProcessStubDispatch::AcceptWithResponder(memory_instrumentation::mojom::ClientProcess*, mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34dbfc0  [callback_internal.h:164]
    +                                                                                   520 memory_instrumentation::ClientProcessImpl::RequestOSMemoryDump(bool, std::__1::vector<int, std::__1::allocator<int> > const&, base::RepeatingCallback<void (bool, std::__1::unordered_map<int, mojo::StructPtr<memory_instrumentation::mojom::RawOSMemDump>, std::__1::hash<int>, std::__1::equal_to<int>, std::__1::allocator<std::__1::pair<int const, mojo::StructPtr<memory_instrumentation::mojom::RawOSMemDump> > > >)> const&)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d071c  [client_process_impl.cc:140]
    +                                                                                     520 memory_instrumentation::OSMetrics::FillProcessMemoryMaps(int, memory_instrumentation::mojom::RawOSMemDump*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d2061  [vector:639]
    +                                                                                       516 memory_instrumentation::OSMetrics::GetProcessMemoryMaps(int)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d2628  [os_metrics_mac.cc:163]
    +                                                                                       ! 516 proc_regionfilename  (in libsystem_kernel.dylib) + 74  [0x7fff5b3b3411]
    +                                                                                       !   516 __proc_info  (in libsystem_kernel.dylib) + 10  [0x7fff5b3bbc46]
    +                                                                                       3 memory_instrumentation::OSMetrics::GetProcessMemoryMaps(int)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d25d4  [os_metrics_mac.cc:147]
    +                                                                                       ! 3 base::GetBasicInfo(unsigned int, unsigned long long*, unsigned long long*, vm_region_basic_info_64*)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x211c167  [process_metrics_mac.cc:342]
    +                                                                                       !   3 mach_vm_region  (in libsystem_kernel.dylib) + 142  [0x7fff5b3a9187]
    +                                                                                       !     3 mach_msg  (in libsystem_kernel.dylib) + 60  [0x7fff5b3b1cdc]
    +                                                                                       !       3 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff5b3b27c2]
    +                                                                                       1 memory_instrumentation::OSMetrics::GetProcessMemoryMaps(int)  (in Google Chrome Framework)  load address 0x10a75b000 + 0x34d26a0  [memory_instrumentation.mojom.h:1432]

 
hung-canary-browser-process-symbolized.txt
487 KB View Download

Comment 1 by kbr@chromium.org, Mar 28 2018

Note: at this point in time according to Activity Monitor:

Physical memory: 16.00 GB
Memory used: 13.71 GB
Cached files: 2.15 GB
Swap used: 2.42 GB

Comment 2 by lgrey@chromium.org, Mar 28 2018

Cc: erikc...@chromium.org
Owner: erikc...@chromium.org
Status: Assigned (was: Untriaged)
Woah, very not good. Thanks for pointing this out. 

Comment 4 by kbr@chromium.org, Mar 29 2018

Note: I'm not sure this is reproducible any more after a browser restart. But thanks for looking into it with urgency.

Cc: primiano@chromium.org hjd@chromium.org
There are several problems here.

1) We're fetching VMRegions on the main thread.
2) We're calling proc_regionfilename on every VMRegion. Looking at the implementation, this eventually hits... proc_pidregionpathinfo, which calls fill_procregioninfo, which calls vm_map_region_walk, which iterates through every virtual page of the region. This is highly inefficient

To fix (1), we should dispatch off the main thread
To fix (2), we should be able to just iterate through dyld regions [which we already do] to get relevant filenames for the OOP HP. To ensure consistency with other OSes we should probably keep the logic for DETAILED heap dumps.

Comment 6 by kbr@chromium.org, Apr 5 2018

Is there any progress on this? Chrome Canary on my Mac laptop is performing extremely poorly. I have a lot of tabs open and am seeing frequent multi-second hangs during scrolling. I haven't gathered a sample to prove that this code is the problem but suspect that it is.

There's a CL that was stalled for a bit on primiano being OOO. Now it's stalled on me fixing the compile errors and landing:
https://chromium-review.googlesource.com/c/chromium/src/+/986680
Project Member

Comment 8 by bugdroid1@chromium.org, Apr 6 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/ec6a7a25ba71c1aec895612aceb449fd4d59459d

commit ec6a7a25ba71c1aec895612aceb449fd4d59459d
Author: Erik Chen <erikchen@chromium.org>
Date: Fri Apr 06 10:10:31 2018

Speed up module dumps on macOS.

The out of process heap profiler only requires modules to be dumped, not every
single virtual memory region. This CL modifies the interface to support this,
and updates the macOS implementation to be much faster. The other OSes currently
still perform full address space dumps - this can be changed in the future if it
proves to be a performance issue.

Bug:  826913 
Change-Id: Ibaa03d3dfae71a2b6d090aed0ab2ffdc4bb090a9
Reviewed-on: https://chromium-review.googlesource.com/986680
Commit-Queue: Erik Chen <erikchen@chromium.org>
Reviewed-by: Primiano Tucci <primiano@chromium.org>
Reviewed-by: Daniel Cheng <dcheng@chromium.org>
Cr-Commit-Position: refs/heads/master@{#548731}
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/base/trace_event/memory_dump_request_args.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/base/trace_event/memory_dump_request_args.h
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/base/trace_event/memory_dump_scheduler.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/memory_instrumentation/coordinator_impl_unittest.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/memory_instrumentation/queued_request.h
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/memory_instrumentation/queued_request_dispatcher.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/client_process_impl.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/client_process_impl.h
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/os_metrics.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/os_metrics.h
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/os_metrics_mac.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/cpp/memory_instrumentation/os_metrics_unittest.cc
[modify] https://crrev.com/ec6a7a25ba71c1aec895612aceb449fd4d59459d/services/resource_coordinator/public/mojom/memory_instrumentation/memory_instrumentation.mojom

Status: Fixed (was: Assigned)
This should be fixed - let me know if you see this again.

Comment 10 by kbr@chromium.org, May 10 2018

Blocking: 841951

Sign in to add a comment