+cc: primiano & lalitm

it repros locally for me too at r540933.

It does not repro anymore for me at r541226.

Was it crashing at startup? I'm trying to revert the CL mentioned in c0 (in https://chromium-review.googlesource.com/c/chromium/src/+/955923) and I'm not hitting this DCHECK.

Just saw this crash on a debug build on r541186.
It was not on startup - it happened while I left the browser open during lunch.

I am seeing this happening repeatedly. I'm running a Chromium build, I don't think I'm doing anything particularly interesting other than leaving it running for several minutes.

Here is most of the Autos window from Visual Studio - I guess the patch_service was already inserted and we tried to insert it again? I'm going to comment out the DCHECK for now.

+		identity	{name_="patch_service" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }	const service_manager::Identity &
-		instances_	{ size=15 }	std::map<service_manager::Identity,unsigned long,std::less<service_manager::Identity>,std::allocator<std::pair<const service_manager::Identity,unsigned long> > >
+		[comparator]	less	std::_Compressed_pair<std::less<service_manager::Identity>,std::_Compressed_pair<std::allocator<std::_Tree_node<std::pair<const service_manager::Identity,unsigned long>,void *> >,std::_Tree_val<std::_Tree_simple_types<std::pair<const service_manager::Identity,unsigned long> > >,1>,1>
+		[allocator]	allocator	std::_Compressed_pair<std::allocator<std::_Tree_node<std::pair<const service_manager::Identity,unsigned long>,void *> >,std::_Tree_val<std::_Tree_simple_types<std::pair<const service_manager::Identity,unsigned long> > >,1>
+		[{name_="audio" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	52376	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="catalog" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	34772	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_browser" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	34772	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_browser" user_id_="e19ff48e-cfcc-4b4f-9589-73e7942a0bf2" instance_="" }]	34772	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_gpu" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="2" }]	27704	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_packaged_services" user_id_="205fc0d0-60d7-4772-a57d-3228a98adc2c" instance_="" }]	34772	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_renderer" user_id_="e19ff48e-cfcc-4b4f-9589-73e7942a0bf2" instance_="11_1" }]	43564	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_renderer" user_id_="e19ff48e-cfcc-4b4f-9589-73e7942a0bf2" instance_="12_1" }]	19892	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_renderer" user_id_="e19ff48e-cfcc-4b4f-9589-73e7942a0bf2" instance_="13_1" }]	52808	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_utility" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="22" }]	19572	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_utility" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="5" }]	9088	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="content_utility" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="9" }]	52376	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="patch_service" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	19572	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="proxy_resolver" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	9088	std::pair<const service_manager::Identity,unsigned long>
+		[{name_="service_manager" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }]	34772	std::pair<const service_manager::Identity,unsigned long>
+		[Raw View]	{...}	std::map<service_manager::Identity,unsigned long,std::less<service_manager::Identity>,std::allocator<std::pair<const service_manager::Identity,unsigned long> > >
+		it_and_inserted	(({name_="patch_service" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }, 19572), false)	std::pair<std::_Tree_iterator<std::_Tree_val<std::_Tree_simple_types<std::pair<const service_manager::Identity,unsigned long> > > >,bool>
		it_and_inserted.second	false	bool
		pid	9784	unsigned int

More specifically, the failure happened because an item with:

identity: {name_="patch_service" user_id_="505C0EE9-3013-43C0-82B0-A84F50CF8D84" instance_="" }

was inserted when it already existed in the map (duplicate names are fine, duplicate identities are not).

Is this useful information? Is there additional data that I should try to grab?

As I said, I wasn't doing anything particularly unusual, just running a debug build and letting it sit for a few minutes. It would be great to get this fixed, both to fix the presumed correctness problems and to avoid having this DCHECK fire while investigating other bugs.

+rockot@, is it expected that we get to see two services with the same identity? That seems quite unexpected to me. Is this a bug of the Service Manager callbacks?

Bruce, thanks for filing this and dumping the identity strings, should definitely help.

Moving over to Lalit who is more familiar with that code.

Yeah unfortunately I think the API is racy. If an instance $id dies or becomes unreachable by the service manager, and a new connection to the same $id is requested immediately after that, a new instance with $id will be created. It's then possible for a ServiceMangaerListener to receive the new instance's OnServicePIDReceived before it receives the old instance's OnServiceStopped. This same essential problem is covered by  bug 840127 .

This hit again, somebody pinged me because tryjobs were failing on [1].
The fact that the ServiceMangaerListener API is racy is really unfortunate.
For the moment I'm going to force-replace entries and remove that dcheck, but I guess at some point we'll pay this and some metrics will be skewed if something else will go wrong and undetected.


[1] https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket.appspot.com/8932942268393419584/+/steps/browser_tests__with_patch_/0/stdout

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

commit 5203a4a475d0eb4c10ddacd9728ca6803c07487f
Author: Kyle Horimoto <khorimoto@google.com>
Date: Thu Oct 11 22:06:43 2018

ProcessMap: Work around racy service listener.

Previously, we would DCHECK() that the ProcessMap did not contain an
identity when initializing it. However, this led to some false-positives
which resulted in the map containing spurious entries.

This CL updates ProcessMap::OnInit() to work around this issue by
removing any existing entries for a given identity before trying to add
new ones.

Bug:  818593 ,  884066 
Change-Id: Ic69af1f6b622dc73dde8fb09ad659b887857e384
Reviewed-on: https://chromium-review.googlesource.com/c/1277808
Commit-Queue: Kyle Horimoto <khorimoto@chromium.org>
Reviewed-by: Primiano Tucci <primiano@chromium.org>
Cr-Commit-Position: refs/heads/master@{#598972}
[modify] https://crrev.com/5203a4a475d0eb4c10ddacd9728ca6803c07487f/services/resource_coordinator/memory_instrumentation/process_map.cc

 Issue 893253  has been merged into this issue.

This is still happening. It just happened on a repo that is up-to-date to November 9th, a month after the presumed fix was landed. I think we should remove the DCHECK until we figure out why it is being flaky (and reinstate it as a CHECK, or not at all).

crrev.com/c/1334004 is the CL I just created.

Coincidentally, I landed https://crrev.com/606960 on Nov 9. This should actually fix the problem, because it ensures that no exactly identical value of Identity is ever reused.

I'll take this, but I suspect we can close it. Let's see what happens once the CHECK lands.

Oh, wait, I assumed your CL was changing the DCHECK to a CHECK. :)

Maybe we don't need to land it now? Can you try syncing?

Since https://crrev.com/606960 should actually fix it I will abandon my change and resurrect if if I see the DCHECK again. Thanks for the fix.

It is still mysterious that I was able to hit the DCHECK given the workaround landed with crrev.com/c/1277808. I can't explain that (possibly user error?) but all we can do is watch for future issues - or perhaps change the DCHECK to a CHECK.

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

commit 3bdf26ad8f19ee9b629e09eb04ecc95c870fe772
Author: Ken Rockot <rockot@google.com>
Date: Tue Nov 27 18:10:27 2018

Fix raciness in AudioServiceListener

This fixes potential race conditions in AudioServiceListener resulting
from the fact that a service instance can become unreachable (and may
therefore be replaced with a new one) before it is officially designated
as "stopped" by the Service Manager, even in the case of singleton
services.

The ServiceManagerListener API is augmented to convey a service
instance's current running state via RunningServiceInfo. This is used
by AudioServiceListener to more accurately track the running audio
service instance.

The listener now tracks the Identity of the most recently created
audio service instance and responds to events accordingly.

This also updates the logic and comments in resource_coordinator's
ProcessMap to accurately reflect current guarantees of the
ServiceManagerListener API, since these have changed slightly.

NOTRY=true

Bug:  818593 , 907898 ,908319
Change-Id: If3e8a35aa90db72a34c8f5f2d458f0f24c3447eb
Reviewed-on: https://chromium-review.googlesource.com/c/1350649
Commit-Queue: Ken Rockot <rockot@google.com>
Reviewed-by: Olga Sharonova <olka@chromium.org>
Reviewed-by: Tom Sepez <tsepez@chromium.org>
Reviewed-by: oysteine <oysteine@chromium.org>
Cr-Commit-Position: refs/heads/master@{#611193}
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/content/browser/renderer_host/media/audio_service_listener.cc
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/content/browser/renderer_host/media/audio_service_listener.h
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/content/browser/renderer_host/media/audio_service_listener_unittest.cc
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/services/resource_coordinator/memory_instrumentation/process_map.cc
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/services/service_manager/public/mojom/service_manager.mojom
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/services/service_manager/service_manager.cc
[modify] https://crrev.com/3bdf26ad8f19ee9b629e09eb04ecc95c870fe772/services/service_manager/service_manager.h