Commit 3bdf26ad authored by Ken Rockot's avatar Ken Rockot Committed by Commit Bot

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: default avatarOlga Sharonova <olka@chromium.org>
Reviewed-by: default avatarTom Sepez <tsepez@chromium.org>
Reviewed-by: default avataroysteine <oysteine@chromium.org>
Cr-Commit-Position: refs/heads/master@{#611193}
parent 4e5628b8
......@@ -22,10 +22,12 @@ AudioServiceListener::Metrics::Metrics(const base::TickClock* clock)
AudioServiceListener::Metrics::~Metrics() = default;
void AudioServiceListener::Metrics::ServiceAlreadyRunning() {
void AudioServiceListener::Metrics::ServiceAlreadyRunning(
service_manager::mojom::InstanceState state) {
LogServiceStartStatus(ServiceStartStatus::kAlreadyStarted);
started_ = clock_->NowTicks();
initial_downtime_start_ = base::TimeTicks();
if (state == service_manager::mojom::InstanceState::kStarted)
started_ = clock_->NowTicks();
}
void AudioServiceListener::Metrics::ServiceCreated() {
......@@ -73,6 +75,8 @@ void AudioServiceListener::Metrics::ServiceStopped() {
UMA_HISTOGRAM_CUSTOM_TIMES("Media.AudioService.ObservedUptime",
stopped_ - started_, base::TimeDelta(),
base::TimeDelta::FromDays(7), 50);
created_ = base::TimeTicks();
started_ = base::TimeTicks();
}
......@@ -115,10 +119,17 @@ void AudioServiceListener::OnInit(
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
for (const service_manager::mojom::RunningServiceInfoPtr& instance :
running_services) {
if (instance->identity.name() == audio::mojom::kServiceName) {
process_id_ = instance->pid;
metrics_.ServiceAlreadyRunning();
if (instance->identity.name() == audio::mojom::kServiceName &&
instance->state !=
service_manager::mojom::InstanceState::kUnreachable) {
current_instance_identity_ = instance->identity;
current_instance_state_ = instance->state;
metrics_.ServiceAlreadyRunning(instance->state);
MaybeSetLogFactory();
// NOTE: This may not actually be a valid PID yet. If not, we will
// receive OnServicePIDReceived soon.
process_id_ = instance->pid;
break;
}
}
......@@ -129,6 +140,24 @@ void AudioServiceListener::OnServiceCreated(
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
if (service->identity.name() != audio::mojom::kServiceName)
return;
if (current_instance_identity_) {
// If we were already tracking an instance of the service, it must be dying
// soon. We'll start tracking the new instance instead now, so simulate
// stoppage of the old one.
DCHECK(service->identity != current_instance_identity_);
if (current_instance_state_ ==
service_manager::mojom::InstanceState::kCreated) {
OnServiceFailedToStart(*current_instance_identity_);
} else {
DCHECK_EQ(service_manager::mojom::InstanceState::kStarted,
*current_instance_state_);
OnServiceStopped(*current_instance_identity_);
}
}
current_instance_identity_ = service->identity;
current_instance_state_ = service_manager::mojom::InstanceState::kCreated;
metrics_.ServiceCreated();
MaybeSetLogFactory();
}
......@@ -139,7 +168,11 @@ void AudioServiceListener::OnServiceStarted(
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
if (identity.name() != audio::mojom::kServiceName)
return;
process_id_ = pid;
DCHECK(identity == current_instance_identity_);
DCHECK(current_instance_state_ ==
service_manager::mojom::InstanceState::kCreated);
current_instance_state_ = service_manager::mojom::InstanceState::kStarted;
metrics_.ServiceStarted();
}
......@@ -147,30 +180,41 @@ void AudioServiceListener::OnServicePIDReceived(
const ::service_manager::Identity& identity,
uint32_t pid) {
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
if (identity.name() != audio::mojom::kServiceName)
if (identity != current_instance_identity_)
return;
process_id_ = pid;
}
void AudioServiceListener::OnServiceFailedToStart(
const ::service_manager::Identity& identity) {
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
if (identity.name() != audio::mojom::kServiceName)
if (identity != current_instance_identity_)
return;
metrics_.ServiceFailedToStart();
current_instance_identity_.reset();
current_instance_state_.reset();
process_id_ = base::kNullProcessId;
log_factory_is_set_ = false;
}
void AudioServiceListener::OnServiceStopped(
const ::service_manager::Identity& identity) {
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
if (identity.name() != audio::mojom::kServiceName)
if (identity != current_instance_identity_)
return;
metrics_.ServiceStopped();
current_instance_identity_.reset();
current_instance_state_.reset();
process_id_ = base::kNullProcessId;
log_factory_is_set_ = false;
}
void AudioServiceListener::MaybeSetLogFactory() {
DCHECK_CALLED_ON_VALID_SEQUENCE(owning_sequence_);
DCHECK(current_instance_identity_);
if (!base::FeatureList::IsEnabled(features::kAudioServiceOutOfProcess) ||
!connector_ || log_factory_is_set_)
return;
......@@ -179,7 +223,7 @@ void AudioServiceListener::MaybeSetLogFactory() {
mojo::MakeStrongBinding(std::make_unique<AudioLogFactory>(),
mojo::MakeRequest(&audio_log_factory_ptr));
audio::mojom::LogFactoryManagerPtr log_factory_manager_ptr;
connector_->BindInterface(audio::mojom::kServiceName,
connector_->BindInterface(*current_instance_identity_,
mojo::MakeRequest(&log_factory_manager_ptr));
log_factory_manager_ptr->SetLogFactory(std::move(audio_log_factory_ptr));
log_factory_is_set_ = true;
......
......@@ -9,11 +9,13 @@
#include <vector>
#include "base/gtest_prod_util.h"
#include "base/optional.h"
#include "base/process/process_handle.h"
#include "base/time/time.h"
#include "content/common/content_export.h"
#include "mojo/public/cpp/bindings/binding.h"
#include "services/service_manager/public/cpp/connector.h"
#include "services/service_manager/public/cpp/identity.h"
#include "services/service_manager/public/mojom/service_manager.mojom.h"
namespace base {
......@@ -22,6 +24,7 @@ class TickClock;
namespace content {
// Tracks the system's active audio service instance, if any exists.
class CONTENT_EXPORT AudioServiceListener
: public service_manager::mojom::ServiceManagerListener {
public:
......@@ -39,7 +42,7 @@ class CONTENT_EXPORT AudioServiceListener
explicit Metrics(const base::TickClock* clock);
~Metrics();
void ServiceAlreadyRunning();
void ServiceAlreadyRunning(service_manager::mojom::InstanceState state);
void ServiceCreated();
void ServiceFailedToStart();
void ServiceStarted();
......@@ -77,18 +80,20 @@ class CONTENT_EXPORT AudioServiceListener
running_services) override;
void OnServiceCreated(
service_manager::mojom::RunningServiceInfoPtr service) override;
void OnServiceStarted(const ::service_manager::Identity& identity,
void OnServiceStarted(const service_manager::Identity& identity,
uint32_t pid) override;
void OnServicePIDReceived(const ::service_manager::Identity& identity,
void OnServicePIDReceived(const service_manager::Identity& identity,
uint32_t pid) override;
void OnServiceFailedToStart(
const ::service_manager::Identity& identity) override;
void OnServiceStopped(const ::service_manager::Identity& identity) override;
const service_manager::Identity& identity) override;
void OnServiceStopped(const service_manager::Identity& identity) override;
void MaybeSetLogFactory();
mojo::Binding<service_manager::mojom::ServiceManagerListener> binding_;
std::unique_ptr<service_manager::Connector> connector_;
base::Optional<service_manager::Identity> current_instance_identity_;
base::Optional<service_manager::mojom::InstanceState> current_instance_state_;
base::ProcessId process_id_ = base::kNullProcessId;
Metrics metrics_;
bool log_factory_is_set_ = false;
......
......@@ -34,6 +34,7 @@ RunningServiceInfoPtr MakeTestServiceInfo(
RunningServiceInfoPtr info(service_manager::mojom::RunningServiceInfo::New());
info->identity = identity;
info->pid = pid;
info->state = service_manager::mojom::InstanceState::kStarted;
return info;
}
......@@ -73,6 +74,7 @@ TEST_F(AudioServiceListenerMetricsTest,
CreateMetricsStartService_LogsInitialDowntime) {
AudioServiceListener::Metrics metrics(&test_clock);
test_clock.Advance(base::TimeDelta::FromHours(12));
metrics.ServiceCreated();
metrics.ServiceStarted();
histogram_tester.ExpectTimeBucketCount(
"Media.AudioService.ObservedInitialDowntime",
......@@ -82,7 +84,8 @@ TEST_F(AudioServiceListenerMetricsTest,
TEST_F(AudioServiceListenerMetricsTest,
ServiceAlreadyRunningStopService_LogsUptime) {
AudioServiceListener::Metrics metrics(&test_clock);
metrics.ServiceAlreadyRunning();
metrics.ServiceAlreadyRunning(
service_manager::mojom::InstanceState::kStarted);
test_clock.Advance(base::TimeDelta::FromMinutes(42));
metrics.ServiceStopped();
histogram_tester.ExpectTimeBucketCount("Media.AudioService.ObservedUptime",
......@@ -92,8 +95,10 @@ TEST_F(AudioServiceListenerMetricsTest,
TEST_F(AudioServiceListenerMetricsTest,
ServiceAlreadyRunningCreateService_LogsStartupTime) {
AudioServiceListener::Metrics metrics(&test_clock);
metrics.ServiceAlreadyRunning();
metrics.ServiceAlreadyRunning(
service_manager::mojom::InstanceState::kStarted);
test_clock.Advance(base::TimeDelta::FromMilliseconds(2));
metrics.ServiceStopped();
metrics.ServiceCreated();
test_clock.Advance(base::TimeDelta::FromMilliseconds(20));
metrics.ServiceStarted();
......@@ -102,13 +107,14 @@ TEST_F(AudioServiceListenerMetricsTest,
base::TimeDelta::FromMilliseconds(20), 1);
}
// Check that if service was already started and ServiceStarted() is called,
// Check that if service was already created and ServiceStarted() is called,
// ObservedStartupTime and ObservedInitialDowntime are not logged and start time
// is reset.
TEST_F(AudioServiceListenerMetricsTest,
ServiceAlreadyRunningStartService_ResetStartTime) {
AudioServiceListener::Metrics metrics(&test_clock);
metrics.ServiceAlreadyRunning();
metrics.ServiceAlreadyRunning(
service_manager::mojom::InstanceState::kCreated);
test_clock.Advance(base::TimeDelta::FromMilliseconds(20));
metrics.ServiceStarted();
histogram_tester.ExpectTotalCount("Media.AudioService.ObservedStartupTime",
......@@ -180,15 +186,4 @@ TEST(AudioServiceListenerTest, OnInitWithAudioService_ProcessIdNotNull) {
EXPECT_EQ(pid, audio_service_listener.GetProcessId());
}
TEST(AudioServiceListenerTest, OnAudioServiceCreated_ProcessIdNotNull) {
AudioServiceListener audio_service_listener(nullptr);
service_manager::Identity audio_service_identity =
MakeFakeId(audio::mojom::kServiceName);
constexpr base::ProcessId pid(42);
audio_service_listener.OnServiceCreated(
MakeTestServiceInfo(audio_service_identity, pid));
audio_service_listener.OnServiceStarted(audio_service_identity, pid);
EXPECT_EQ(pid, audio_service_listener.GetProcessId());
}
} // namespace content
......@@ -28,22 +28,16 @@ ProcessMap::ProcessMap(service_manager::Connector* connector) : binding_(this) {
binding_.Bind(std::move(request));
}
ProcessMap::~ProcessMap() {}
ProcessMap::~ProcessMap() = default;
void ProcessMap::OnInit(std::vector<RunningServiceInfoPtr> instances) {
for (const RunningServiceInfoPtr& instance : instances) {
if (instance->pid == base::kNullProcessId)
continue;
const service_manager::Identity& identity = instance->identity;
// TODO(https://crbug.com/818593): The listener interface is racy, so the
// map may contain spurious entries. If so, remove the existing entry before
// adding a new one.
if (base::ContainsKey(instances_, identity))
OnServiceStopped(identity);
auto it_and_inserted = instances_.emplace(identity, instance->pid);
// This must succeed. Every instance has a globally unique Identity.
auto it_and_inserted =
instances_.emplace(instance->identity, instance->pid);
DCHECK(it_and_inserted.second);
}
}
......@@ -63,10 +57,13 @@ void ProcessMap::OnServiceStopped(const service_manager::Identity& identity) {
void ProcessMap::OnServicePIDReceived(const service_manager::Identity& identity,
uint32_t pid) {
if (pid == base::kNullProcessId)
return;
auto it_and_inserted = instances_.emplace(identity, pid);
DCHECK(it_and_inserted.second);
// Either we didn't have the PID before and emplacement succeeded above, or
// we already had a valid PID for this Identity from |OnInit()|. In the latter
// case, the PID received here must match that one.
DCHECK(it_and_inserted.second ||
it_and_inserted.first->second == base::ProcessId(pid));
}
base::ProcessId ProcessMap::GetProcessId(
......
......@@ -6,10 +6,37 @@ module service_manager.mojom;
import "services/service_manager/public/mojom/connector.mojom";
enum InstanceState {
// The instance has been created by the Service Manager but has not yet
// started running. A ServiceManagerListener which observes an instance in
// this state during |OnInit()| will not observe an |OnServiceCreated()|
// message for that instance. Instead the next message received regarding that
// instance will be either |OnServiceStarted()| or |OnServiceFailedToStart()|.
kCreated,
// The instance is running and accepting interface requests from the Service
// Manager. A ServiceManagerListener which observes an instance in this state
// during |OnInit()| will not observe an |OnServiceCreated()|,
// |OnServiceStarted()|, or |OnServiceFailedToStart()| message for that
// instance. If the instance did not have a valid |pid| during |OnInit()|, the
// listener may receive on |OnServicePIDReceived()| message at some point in
// the future. The only other event the listener may observe for that instance
// is |OnServiceStopped()|.
kStarted,
// The instance is still running and may be connected to other service
// instances in the system, but it is no longer reachable through the Service
// Manager. A ServiceManagerListener which observes an instance in this state
// during |OnInit()| can expect to eventually observe an |OnServiceStopped()|
// event for that instance. No other events will be observed regarding that
// instance.
kUnreachable,
};
struct RunningServiceInfo {
uint32 id;
Identity identity;
uint32 pid;
InstanceState state;
};
// Implemented by a client that wishes to be informed when the list of running
......@@ -23,14 +50,24 @@ interface ServiceManagerListener {
// Called when the Service Manager has started tracking a Service. This
// happens when the Service Manager first handles a request to launch the
// Service, before a process is created for it.
//
// TODO(https://crbug.com/908319): This should just take an Identity instead
// of a RunningServiceInfo. Newly created service instances never have a PID
// and are always in the |kCreated| state.
OnServiceCreated(RunningServiceInfo service);
// Called when a pid is available for the service. This could be because the
// Service Manager created a process for it, or because an existing one was
// assigned to it.
OnServiceStarted(Identity identity, uint32 pid);
//
// NOTE: Implementations should ignore |pid_deprecated|. This message will
// eventually be followed by OnServicePIDReceived for the corresponding
// |identity|, as the instance's PID is not guaranteed to be known when this
// method is invoked.
OnServiceStarted(Identity identity, uint32 pid_deprecated);
// Called when a pid is available for the service.
// Called when a PID is available for the service. Guaranteed to be called
// some time after OnServiceStarted, unless OnServiceStopped is called first.
OnServicePIDReceived(Identity identity, uint32 pid);
// Called when a service failed to start. (typically because it was shutdown
......
......@@ -186,25 +186,23 @@ class ServiceManager::Instance
const InterfaceProviderSpecMap& interface_provider_specs,
const catalog::ServiceOptions& options)
: service_manager_(service_manager),
id_(GenerateUniqueID()),
identity_(identity),
interface_provider_specs_(interface_provider_specs),
options_(options),
allow_any_application_(GetConnectionSpec().requires.count("*") == 1),
pid_receiver_binding_(this),
control_binding_(this),
state_(State::IDLE),
state_(mojom::InstanceState::kCreated),
weak_factory_(this) {
if (identity_.name() == service_manager::mojom::kServiceName ||
identity_.name() == catalog::mojom::kServiceName) {
pid_ = GetCurrentPid();
}
DCHECK_GT(id_, 0u);
DCHECK(identity_.IsValid());
}
void Stop() {
DCHECK_NE(state_, State::STOPPED);
DCHECK(!stopped_);
// Shutdown all bindings. This way the process should see the pipes closed
// and exit, as well as waking up any potential
......@@ -214,22 +212,22 @@ class ServiceManager::Instance
pid_receiver_binding_.Close();
connectors_.CloseAllBindings();
service_manager_bindings_.CloseAllBindings();
service_manager_->OnInstanceUnreachable(this);
MarkUnreachable();
if (state_ == State::STARTING) {
if (state_ == mojom::InstanceState::kCreated) {
service_manager_->NotifyServiceFailedToStart(identity_);
} else {
// Notify the ServiceManager that this Instance is really going away.
service_manager_->OnInstanceStopped(identity_);
}
state_ = State::STOPPED;
stopped_ = true;
}
~Instance() override {
// The instance may have already been stopped prior to destruction if the
// ServiceManager itself is being torn down.
if (state_ != State::STOPPED)
if (!stopped_)
Stop();
}
......@@ -271,8 +269,9 @@ class ServiceManager::Instance
}
void StartWithService(mojom::ServicePtr service) {
service_manager_->NotifyServiceCreated(this);
CHECK(!service_);
state_ = State::STARTING;
service_ = std::move(service);
service_.set_connection_error_handler(
base::BindOnce(&Instance::OnServiceLost, base::Unretained(this),
......@@ -307,9 +306,9 @@ class ServiceManager::Instance
mojom::RunningServiceInfoPtr CreateRunningServiceInfo() const {
mojom::RunningServiceInfoPtr info(mojom::RunningServiceInfo::New());
info->id = id_;
info->identity = identity_;
info->pid = pid_;
info->state = state_;
return info;
}
......@@ -334,8 +333,6 @@ class ServiceManager::Instance
identity_ = identity;
}
uint32_t id() const { return id_; }
// Service:
void OnBindInterface(const BindSourceInfo& source_info,
const std::string& interface_name,
......@@ -353,21 +350,6 @@ class ServiceManager::Instance
}
private:
enum class State {
// The service was not started yet.
IDLE,
// The service was started but the service manager hasn't received the
// initial response from it yet.
STARTING,
// The service was started successfully.
STARTED,
// The service has been stopped.
STOPPED,
};
class InterfaceProviderImpl : public mojom::InterfaceProvider {
public:
InterfaceProviderImpl(Instance* instance,
......@@ -440,6 +422,21 @@ class ServiceManager::Instance
DISALLOW_COPY_AND_ASSIGN(InterfaceProviderImpl);
};
void MarkUnreachable() {
state_ = mojom::InstanceState::kUnreachable;
service_manager_->OnInstanceUnreachable(this);
}
void MaybeNotifyPidAvailable() {
// Ensure that we only notify listeners of the PID after notifying them of
// instance start to ensure consistent ordering of ServiceManagerListener
// messages pertaining to this instance.
if (state_ == mojom::InstanceState::kStarted &&
pid_ != base::kNullProcessId) {
service_manager_->NotifyServicePIDReceived(identity_, pid_);
}
}
// mojom::Connector implementation:
void BindInterface(const service_manager::ServiceFilter& target_filter,
const std::string& interface_name,
......@@ -637,7 +634,7 @@ class ServiceManager::Instance
}
#endif
pid_ = pid;
service_manager_->NotifyServicePIDReceived(identity_, pid_);
MaybeNotifyPidAvailable();
}
void OnServiceLost(
......@@ -654,13 +651,13 @@ class ServiceManager::Instance
if (connectors_.empty())
service_manager->OnInstanceError(this);
else
service_manager->OnInstanceUnreachable(this);
MarkUnreachable();
}
}
void OnStartComplete(mojom::ConnectorRequest connector_request,
mojom::ServiceControlAssociatedRequest control_request) {
state_ = State::STARTED;
state_ = mojom::InstanceState::kStarted;
if (connector_request.is_pending()) {
connectors_.AddBinding(this, std::move(connector_request));
connectors_.set_connection_error_handler(base::BindRepeating(
......@@ -670,6 +667,7 @@ class ServiceManager::Instance
if (control_request.is_pending())
control_binding_.Bind(std::move(control_request));
service_manager_->NotifyServiceStarted(identity_, pid_);
MaybeNotifyPidAvailable();
}
// mojom::ServiceControl:
......@@ -684,7 +682,6 @@ class ServiceManager::Instance
// An id that identifies this instance. Distinct from pid, as a single process
// may vend multiple application instances, and this object may exist before a
// process is launched.
const uint32_t id_;
Identity identity_;
const InterfaceProviderSpecMap interface_provider_specs_;
const catalog::ServiceOptions options_;
......@@ -698,7 +695,8 @@ class ServiceManager::Instance
mojo::BindingSet<mojom::ServiceManager> service_manager_bindings_;
mojo::AssociatedBinding<mojom::ServiceControl> control_binding_;
base::ProcessId pid_ = base::kNullProcessId;
State state_;
mojom::InstanceState state_;
bool stopped_ = false;
std::map<InterfaceProviderImpl*, std::unique_ptr<InterfaceProviderImpl>>
filters_;
......@@ -1312,6 +1310,13 @@ void ServiceManager::EraseInstanceIdentity(Instance* instance) {
identity_to_instance_->Erase(instance->identity());
}
void ServiceManager::NotifyServiceCreated(Instance* instance) {
mojom::RunningServiceInfoPtr info = instance->CreateRunningServiceInfo();
listeners_.ForAllPtrs([&info](mojom::ServiceManagerListener* listener) {
listener->OnServiceCreated(info.Clone());
});
}
void ServiceManager::NotifyServiceStarted(const Identity& identity,
base::ProcessId pid) {
listeners_.ForAllPtrs(
......@@ -1351,11 +1356,6 @@ ServiceManager::Instance* ServiceManager::CreateInstance(
identity_to_instance_->Insert(identity, instance_type, raw_instance);
mojom::RunningServiceInfoPtr info = raw_instance->CreateRunningServiceInfo();
listeners_.ForAllPtrs([&info](mojom::ServiceManagerListener* listener) {
listener->OnServiceCreated(info.Clone());
});
return raw_instance;
}
......
......@@ -133,6 +133,7 @@ class ServiceManager {
// impossible for any call to GetExistingInstance() to return |instance|.
void EraseInstanceIdentity(Instance* instance);
void NotifyServiceCreated(Instance* instance);
void NotifyServiceStarted(const Identity& identity, base::ProcessId pid);
void NotifyServiceFailedToStart(const Identity& identity);
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment