Error during CEF work

[lolovo]

Hello everyone!

[1207/221305:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): �������� ����� �������. (0x57)

What the problem?

CEF 3.2840.1518.gffd843c , Win7ProSP1x64

[magreenblatt]

What steps reproduce the problem?

[lolovo]

Reproduction is quite complicated due to it is occured after some time of work, I've tried many ways of work to understand during what conditions it will occurs, but I can't say for sure.... at least there are some conditions for reproduction after some time of work (in 5-10min): one App (i.e. SimpleApp), several handlers (i.e. SimpleHandler, at least more than one) and several CefBrowser for each SimpleHandler... after some time of work Errors are appeared:

Code: Select all

[1207/221305:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): �������� ����� �������. (0x57)


Breakpoint at DiscardableSharedMemory::Purge give the same stack always and this error occured during desctruction of mojo::edk::RequestContext::~RequestContext() in mojo::edk::NodeChannel::OnChannelMessage in mojo::edk::Channel::OnReadComplete:

Code: Select all

   libcef.dll!base::DiscardableSharedMemory::Purge(base::Time current_time)Line 364   C++
    libcef.dll!discardable_memory::DiscardableSharedMemoryManager::ReduceMemoryUsageUntilWithinLimit(unsigned int limit)Line 568   C++
    libcef.dll!discardable_memory::DiscardableSharedMemoryManager::AllocateLockedDiscardableSharedMemory(int client_id, unsigned int size, int id, base::SharedMemoryHandle * shared_memory_handle)Line 453   C++
    libcef.dll!discardable_memory::`anonymous namespace'::MojoDiscardableSharedMemoryManagerImpl::AllocateLockedDiscardableSharedMemory(unsigned int size, int id, const base::Callback<void __cdecl(mojo::ScopedHandleBase<mojo::SharedBufferHandle>),1,1> & callback)Line 88   C++
    libcef.dll!discardable_memory::mojom::DiscardableSharedMemoryManagerStubDispatch::AcceptWithResponder(discardable_memory::mojom::DiscardableSharedMemoryManager * impl, mojo::internal::SerializationContext * context, mojo::Message * message, mojo::MessageReceiverWithStatus * responder)Line 274   C++
    libcef.dll!discardable_memory::mojom::DiscardableSharedMemoryManagerStub<mojo::RawPtrImplRefTraits<discardable_memory::mojom::DiscardableSharedMemoryManager> >::AcceptWithResponder(mojo::Message * message, mojo::MessageReceiverWithStatus * responder)Line 147   C++
    libcef.dll!mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message * message)Line 310   C++
    libcef.dll!mojo::FilterChain::Accept(mojo::Message * message)Line 40   C++
    libcef.dll!mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message * message)Line 269   C++
    libcef.dll!mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::Message * message, mojo::internal::MultiplexRouter::ClientCallBehavior client_call_behavior, base::SingleThreadTaskRunner * current_task_runner)Line 838   C++
    libcef.dll!mojo::internal::MultiplexRouter::Accept(mojo::Message * message)Line 547   C++
    libcef.dll!mojo::FilterChain::Accept(mojo::Message * message)Line 40   C++
    libcef.dll!mojo::Connector::ReadSingleMessage(unsigned int * read_result)Line 246   C++
    libcef.dll!mojo::Connector::ReadAllAvailableMessages()Line 272   C++
    libcef.dll!mojo::Connector::OnHandleReadyInternal(unsigned int result)Line 205   C++
    libcef.dll!base::internal::Invoker<base::internal::BindState<void (__thiscall net::FtpNetworkTransaction::*)(int),base::internal::UnretainedWrapper<net::FtpNetworkTransaction> >,void __cdecl(int)>::Run(base::internal::BindStateBase * base, int && <unbound_args_0>)Line 343   C++
    libcef.dll!base::internal::RunMixin<base::Callback<void __cdecl(enum gcm::GCMClient::Result),1,1> >::Run(gcm::GCMClient::Result <args_0>)Line 85   C++
    libcef.dll!mojo::Watcher::OnHandleReady(unsigned int result)Line 84   C++
    libcef.dll!mojo::Watcher::CallOnHandleReady(unsigned int context, unsigned int result, MojoHandleSignalsState signals_state, unsigned int flags)Line 104   C++
    libcef.dll!mojo::edk::`anonymous namespace'::CallWatchCallback(void(*)(unsigned int, unsigned int, MojoHandleSignalsState, unsigned int) callback, unsigned int context, unsigned int result, const mojo::edk::HandleSignalsState & signals_state, unsigned int flags)Line 57   C++
    libcef.dll!base::internal::FunctorTraits<void (__cdecl*)(void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int,unsigned int,mojo::edk::HandleSignalsState const &,unsigned int),void>::Invoke<void (__cdecl*const &)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int const &,unsigned int,mojo::edk::HandleSignalsState const &,unsigned int>(void(*)(void(*)(unsigned int, unsigned int, MojoHandleSignalsState, unsigned int), unsigned int, unsigned int, const mojo::edk::HandleSignalsState &, unsigned int) function, void(*)(unsigned int, unsigned int, MojoHandleSignalsState, unsigned int) & <args_0>, const unsigned int & <args_1>, unsigned int && <args_2>, const mojo::edk::HandleSignalsState & <args_3>, unsigned int && <args_4>)Line 164   C++
    libcef.dll!base::internal::Invoker<base::internal::BindState<void (__cdecl*)(void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int,unsigned int,mojo::edk::HandleSignalsState const &,unsigned int),void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int>,void __cdecl(unsigned int,mojo::edk::HandleSignalsState const &,unsigned int)>::RunImpl<void (__cdecl*const &)(void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int,unsigned int,mojo::edk::HandleSignalsState const &,unsigned int),std::tuple<void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int> const &,0,1>(void(*)(void(*)(unsigned int, unsigned int, MojoHandleSignalsState, unsigned int), unsigned int, unsigned int, const mojo::edk::HandleSignalsState &, unsigned int) & functor, const std::tuple<void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int> & bound, base::IndexSequence<0,1> __formal, unsigned int && <unbound_args_0>, const mojo::edk::HandleSignalsState & <unbound_args_1>, unsigned int && <unbound_args_2>)Line 361   C++
    libcef.dll!base::internal::Invoker<base::internal::BindState<void (__cdecl*)(void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int,unsigned int,mojo::edk::HandleSignalsState const &,unsigned int),void (__cdecl*)(unsigned int,unsigned int,MojoHandleSignalsState,unsigned int),unsigned int>,void __cdecl(unsigned int,mojo::edk::HandleSignalsState const &,unsigned int)>::Run(base::internal::BindStateBase * base, unsigned int && <unbound_args_0>, const mojo::edk::HandleSignalsState & <unbound_args_1>, unsigned int && <unbound_args_2>)Line 339   C++
    libcef.dll!base::internal::RunMixin<base::Callback<void __cdecl(unsigned int,mojo::edk::HandleSignalsState const &,unsigned int),1,1> >::Run(unsigned int <args_0>, const mojo::edk::HandleSignalsState & <args_1>, unsigned int <args_2>)Line 85   C++
    libcef.dll!mojo::edk::Watcher::MaybeInvokeCallback(unsigned int result, const mojo::edk::HandleSignalsState & state, unsigned int flags)Line 25   C++
    libcef.dll!mojo::edk::RequestContext::~RequestContext()Line 60   C++
    libcef.dll!mojo::edk::NodeChannel::OnChannelMessage(const void * payload, unsigned int payload_size, std::unique_ptr<std::vector<mojo::edk::PlatformHandle,std::allocator<mojo::edk::PlatformHandle> >,mojo::edk::PlatformHandleVectorDeleter> handles)Line 766   C++
    libcef.dll!mojo::edk::Channel::OnReadComplete(unsigned int bytes_read, unsigned int * next_read_size_hint)Line 564   C++
    libcef.dll!mojo::edk::`anonymous namespace'::ChannelWin::OnIOCompleted(base::MessagePumpForIO::IOContext * context, unsigned long bytes_transfered, unsigned long error)Line 232   C++
    libcef.dll!base::MessagePumpForIO::DoRunLoop()Line 487   C++
    libcef.dll!base::MessagePumpWin::Run(base::MessagePump::Delegate * delegate)Line 58   C++
    libcef.dll!base::MessageLoop::RunHandler()Line 384   C++
    libcef.dll!base::RunLoop::Run()Line 38   C++
    libcef.dll!base::Thread::Run(base::RunLoop * run_loop)Line 246   C++
    libcef.dll!content::BrowserThreadImpl::IOThreadRun(base::RunLoop * run_loop)Line 277   C++
    libcef.dll!content::BrowserThreadImpl::Run(base::RunLoop * run_loop)Line 311   C++
    libcef.dll!base::Thread::ThreadMain()Line 331   C++
    libcef.dll!base::`anonymous namespace'::ThreadFunc(void * params)Line 86   C++


VirtualFree() MEM_DECOMMIT failed in Purge() always with the same variables conditions (old_state.value.i < 0, this->mapped_size_ < this->shared_memory_.mapped_size_ and it's difference = 4096):

Code: Select all

//example of local visible variables
//this->memory_ ==> (char*)0x1f140000 ==> ""
//difference btw this->mapped_size_ (5554176) < this->shared_memory_.mapped_size_ (5558272) always == 4096
this {
   shared_memory_ {external_section_=false name_=L"CrSharedMem_3ac0cbde88effef5416c292446321c959d3e10f171b15c8a001b8b5b291086e4" mapped_file_={handle_=0x00000000} mapped_size_=5558272 memory_=0x1f140000 ready_only_=false requested_size_=5558272}
   mapped_size_ = 5554176
   locked_page_count_ = 1356
   locked_pages_ {size=1356}
   last_known_usage_ {us_=13148584274000000}
}
//i<0
old_state {value={i=-1286745948 u=3998221348 } }
new_state {value={i=0 u=0 } }
current_time {us_=13148584367865820}


Also noticed that all around mojo (I don't know what it is exactly), but after program start i see always the following error:

Code: Select all

[0830/193037.938:ERROR:child_thread_impl.cc(762)] Request for unknown Channel-associated interface: ui::mojom::GpuMain


and for some sites there are the following errors:

Code: Select all

[0830/193133.205:ERROR:interface_registry.cc(203)] Failed to locate a binder for interface: blink::mojom::SensitiveInputVisibilityService requested by: content_renderer exposed by: content_browser via InterfaceProviderSpec "navigation:frame".
[0830/193133.206:WARNING:interface_registry.cc(210)]

InterfaceRegistry(navigation:frame):
Owned by:
  content_browser@ run as: 9ec183a2-d869-4b73-9e3d-a8602c2fefc7

  Providing:
    capability: renderer containing interfaces:
      autofill::mojom::AutofillDriver
      autofill::mojom::PasswordManagerDriver
      blink::mojom::MediaSessionService
      blink::mojom::PermissionService
      blink::mojom::PresentationService
      blink::mojom::SensitiveInputVisibilityService
      blink::mojom::WebBluetoothService
      blink::mojom::WebSocket
      content::mojom::BrowserTarget
      device::VibrationManager
      device::mojom::GeolocationService
      device::mojom::SensorProvider
      device::mojom::VRService
      device::mojom::WakeLockService
      device::nfc::mojom::NFC
      device::usb::DeviceManager
      discardable_memory::mojom::DiscardableSharedMemoryManager
      extensions::KeepAlive
      extensions::mime_handler::MimeHandlerService
      media::mojom::InterfaceFactory
      media::mojom::RemoterFactory
      media::mojom::Renderer
      mojom::MediaDevicesDispatcherHost
      payments::mojom::PaymentRequest
      shape_detection::mojom::BarcodeDetection
      shape_detection::mojom::FaceDetectionProvider
      shape_detection::mojom::TextDetection
      ui::mojom::Gpu

  Requiring:
    From: content_renderer:
      browser

Bound to:
  content_renderer@10_1 run as: 9ec183a2-d869-4b73-9e3d-a8602c2fefc7

  Providing:
    capability: browser containing interfaces:
      blink::mojom::AppBannerController
      blink::mojom::EngagementClient
      blink::mojom::InstallationService
      content::mojom::ImageDownloader
      mojom::MediaDevicesListener

  Requiring:
    From: content_browser:
      renderer

Binders registered for:
 * blink::mojom::MediaSessionService
 * blink::mojom::PermissionService
 * blink::mojom::PresentationService
 * blink::mojom::WebBluetoothService
 * blink::mojom::WebSocket
 * device::VibrationManager
 * device::mojom::GeolocationService
 * device::mojom::VRService
 * device::mojom::WakeLockService
 * media::mojom::InterfaceFactory
 * media::mojom::RemoterFactory
 * mojom::MediaDevicesDispatcherHost

 * - denotes an interface exposed to remote per policy.


unfortunatelly there is no any discardable_shared_memory_manager.mojom.cc in chromium source that mentioned in stack (5 & 6 call from top stack).. at least i didn't find it.

I don't know... may be it will help somehow to understand the issue and found its solution.

[lolovo]

Any suggestions about what it could be? This happened almost in all versions of CEF for my code.

In Debug mode I've realeased that ANY call of VirtualFree in DiscardableSharedMemory::Purge() are failed (none of it are successful)!!! It seems that something is wrong here!!! To get VirtualFree func in DiscardableSharedMemory::Purge() result.value.u should == old_state.value.u otherwise Purge should return false (as described before this condition - "the caller to determine if purging failed because last known usage was incorrect or memory was locked"):

Code: Select all

  // Update |last_known_usage_| to |current_time| if the memory is locked. This
  // allows the caller to determine if purging failed because last known usage
  // was incorrect or memory was locked. In the second case, the caller should
  // most likely wait for some amount of time before attempting to purge the
  // the memory again.
if (result.value.u != old_state.value.u) {


But as I mentioned above when program get to VirtualFree in Purge before it's call new_state.value.u always != old_state.value.u (MSVC debugger didn't see result variable in Debug mode, I don't know why... so I can't see it... and this comparison of new_state & old_state not proper in this case....but I've realized that when new_state.value.u is == old_state.value.u.... and usually it is 0...then Purge return false on this comparison check) and then VirtualFree always failed when called (and before VirtualFree old_state.value.i < 0 (like -1286105824) and u>0 (like 3008861472)...it seems that memory already can be free at this moment?).... I can only proposed that: there is no proper control of lock states in Purge and at moment of VirtualFree they are changed, for example... i.e. there is no proper lock/control for this part of code (and may be somewhere at the same time this memory is changed or its state) and this should be fixed!

As I understand this is a chromium part... not CEF (?) should I post it to their forum?

Can it be tested properly some how? Is there any tests for this?

[lolovo]

I've build libcef from source and now I'm able to see result in Purge... it is same with old_state...
According to https://bugs.chromium.org/p/chromium/issues/detail?id=661257 it's seems that there are some improvements of shared memory in progress... ?!

One more thing I've discovered... DiscardableSharedMemory::Lock & DiscardableSharedMemory::Unlock never called during program work (breakpoints at the begining never reached)... is it never used?!

And I also wonder.... is there a possibility to avoid usage of shared memory or somehow change this part of code/realization to another available in chromium/cef?

[lolovo]

The latest version of CEF doesn't resolve the issue (after some time of work errors are appeared):

Code: Select all

[0904/132508.666:ERROR:discardable_shared_memory.cc(371)] VirtualFree() MEM_DECOMMIT failed in Purge(): The parameter is incorrect. (0x57)
[0904/132508.668:ERROR:discardable_shared_memory.cc(371)] VirtualFree() MEM_DECOMMIT failed in Purge(): The parameter is incorrect. (0x57)


[lolovo]

Finally I've got steps to reproduce the problem:
(notes: due to the problem triggers when memory usage exceeds the limits > 1024*1024*512bytes, it is best to set appropriate flag to lower this limit for reproduction - i.e. --enable-low-end-device-mode to make Purge work when memory limit exceeds)

1. execute "cefclient.exe --enable-low-end-device-mode"
2. write address "https://www.facebook.com/VinDiesel" to the address box and press enter
3. press ok button about console.log
4. press menu "Test"->"New Window"
5. repeat 2-3 several times to open at least 4-5 windows
6. see debug.log:
[0905/164331.854:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
[0905/164332.536:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
[0905/164333.200:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
[0905/164333.770:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
[0905/164334.487:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
[0905/164334.775:ERROR:discardable_shared_memory.cc(364)] VirtualFree() MEM_DECOMMIT failed in Purge(): Parameter is incorrect. (0x57)
...
7. if there is no errors try to open more windows.. for me several - enough for sure


with time application will crash due to this VirtualFree Purge bug:
[0904/180144.363:FATAL:mem_backend_impl.cc(111)] Check failed: CheckLRUListOrder(lru_list_).

[HarmlessDave]

How much RAM is available to the app? In Windows each chromium tab / window is using over 110 MB for that page, with a peak of around 150 MB each.

We have had our app crash when loading pages with 13 megpixel photos on them, because Chromium decodes them to their full size before scaling them down, causing over 1 GB of memory allocations (2 x 521 MB buffers). The Chromium devs are working to fix this.

[lolovo]

16Gb of RAM more than enough, but the problem not in memory availability but in purging algorithm when internal limits exceed! Default limit is minimum of 1024*1024*512bytes(~536Mb) and 25% of phisical memory... In my case it is 536Mb, so when located size exceeds it's starts reducing memory usage and purging memory that long time was unused.... and every call of VirtualFree gives 0x57 error (invalid parameter) - so it seems that this part of code didn't tested properly... and during this there are also sorting memory segments by last_used_time... so I think when fatal error is happened with checking that LRU list is sorted properly... this can be due to not proper lock control of work with this list.... or list wasn't sort properly due to some errors (it could be also result of not correct work of purging algorithm)