Store a stacktrace of PrefService destruction in PrefChangeRegistrar

Store a stacktrace of PrefService destruction in PrefChangeRegistrar to debug a
race condition: ~PrefChangeRegistrar causes a crash. The current hypothesis is
that this is caused because the PrefChangeRegistrar is registered to a Profile
that is already destroyed. This code stores stacktrace when the Profile's
PrefService is destroyed to see whether this is correct.

BUG=373435

Review URL: https://codereview.chromium.org/290083006

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@271416 0039d316-1c4b-4281-b951-d872f2087c98

base/prefs/pref_change_registrar.cc

@@ -5,6 +5,8 @@
 #include "base/prefs/pref_change_registrar.h"
 
 #include "base/bind.h"
+// TODO(battre): Delete this. See crbug.com/373435.
+#include "base/debug/alias.h"
 #include "base/logging.h"
 #include "base/prefs/pref_service.h"
 
@@ -48,6 +50,19 @@ void PrefChangeRegistrar::Remove(const char* path) {
 }
 
 void PrefChangeRegistrar::RemoveAll() {
+  // TODO(battre): Delete this. See crbug.com/373435.
+  if (!observers_.empty() && !pref_service_destruction_.empty()) {
+    // The PrefService is already destroyed, so the following call to
+    // service_->RemovePrefObserver would crash anyway. When the PrefService
+    // was destroyed, it stored a stack trace of the destruction in
+    // pref_service_destruction_. We save this on the stack in the minidump to
+    // understand what happens.
+    char tmp[2048] = {};
+    strncat(tmp, pref_service_destruction_.c_str(), sizeof(tmp) - 1u);
+    base::debug::Alias(tmp);
+    CHECK(false) << tmp;
+  }
+
   for (ObserverMap::const_iterator it = observers_.begin();
        it != observers_.end(); ++it) {
     service_->RemovePrefObserver(it->first.c_str(), this);
@@ -81,6 +96,12 @@ void PrefChangeRegistrar::OnPreferenceChanged(PrefService* service,
     observers_[pref].Run(pref);
 }
 
+// TODO(battre): Delete this. See crbug.com/373435.
+void PrefChangeRegistrar::SetPrefServiceDestructionTrace(
+    const std::string& stack_trace) {
+  pref_service_destruction_ = stack_trace;
+}
+
 void PrefChangeRegistrar::InvokeUnnamedCallback(const base::Closure& callback,
                                                 const std::string& pref_name) {
   callback.Run();

base/prefs/pref_change_registrar.h

@@ -66,6 +66,9 @@ class BASE_PREFS_EXPORT PrefChangeRegistrar : public PrefObserver {
   // PrefObserver:
   virtual void OnPreferenceChanged(PrefService* service,
                                    const std::string& pref_name) OVERRIDE;
+  // TODO(battre): Delete function. See crbug.com/373435.
+  virtual void SetPrefServiceDestructionTrace(
+      const std::string& stack_trace) OVERRIDE;
 
   static void InvokeUnnamedCallback(const base::Closure& callback,
                                     const std::string& pref_name);
@@ -74,6 +77,8 @@ class BASE_PREFS_EXPORT PrefChangeRegistrar : public PrefObserver {
 
   ObserverMap observers_;
   PrefService* service_;
+  // TODO(battre): Remove attribute (debugging tool for crbug.com/373435).
+  std::string pref_service_destruction_;
 
   DISALLOW_COPY_AND_ASSIGN(PrefChangeRegistrar);
 };

base/prefs/pref_member.cc

@@ -6,6 +6,8 @@
 
 #include "base/callback.h"
 #include "base/callback_helpers.h"
+// TODO(battre): Delete this. See crbug.com/373435.
+#include "base/debug/alias.h"
 #include "base/location.h"
 #include "base/prefs/pref_service.h"
 #include "base/value_conversions.h"
@@ -47,6 +49,18 @@ void PrefMemberBase::Init(const char* pref_name,
 
 void PrefMemberBase::Destroy() {
   if (prefs_ && !pref_name_.empty()) {
+    // TODO(battre): Delete this. See crbug.com/373435.
+    if (!pref_service_destruction_.empty()) {
+      // The PrefService is already destroyed, so the following call to
+      // service_->RemovePrefObserver would crash anyway. When the PrefService
+      // was destroyed, it stored a stack trace of the destruction in
+      // pref_service_destruction_. We save this on the stack in the minidump to
+      // understand what happens.
+      char tmp[2048] = {};
+      strncat(tmp, pref_service_destruction_.c_str(), sizeof(tmp) - 1u);
+      base::debug::Alias(tmp);
+      CHECK(false) << tmp;
+    }
     prefs_->RemovePrefObserver(pref_name_.c_str(), this);
     prefs_ = NULL;
   }
@@ -68,6 +82,12 @@ void PrefMemberBase::OnPreferenceChanged(PrefService* service,
       base::Bind(observer_, pref_name) : base::Closure());
 }
 
+// TODO(battre): Delete this. See crbug.com/373435.
+void PrefMemberBase::SetPrefServiceDestructionTrace(
+    const std::string& stack_trace) {
+  pref_service_destruction_ = stack_trace;
+}
+
 void PrefMemberBase::UpdateValueFromPref(const base::Closure& callback) const {
   VerifyValuePrefName();
   const PrefService::Preference* pref =

base/prefs/pref_member.h

@@ -117,6 +117,9 @@ class BASE_PREFS_EXPORT PrefMemberBase : public PrefObserver {
   // PrefObserver
   virtual void OnPreferenceChanged(PrefService* service,
                                    const std::string& pref_name) OVERRIDE;
+  // TODO(battre): Remove function (debugging tool for crbug.com/373435).
+  virtual void SetPrefServiceDestructionTrace(
+      const std::string& stack_trace) OVERRIDE;
 
   void VerifyValuePrefName() const {
     DCHECK(!pref_name_.empty());
@@ -144,6 +147,8 @@ class BASE_PREFS_EXPORT PrefMemberBase : public PrefObserver {
   std::string pref_name_;
   NamedChangeCallback observer_;
   PrefService* prefs_;
+  // TODO(battre): Remove attribute (debugging tool for crbug.com/373435).
+  std::string pref_service_destruction_;
 
  protected:
   bool setting_value_;

base/prefs/pref_notifier.h

@@ -21,6 +21,12 @@ class PrefNotifier {
 
   // Broadcasts the intialization completed notification.
   virtual void OnInitializationCompleted(bool succeeded) = 0;
+
+  // TODO(battre): Remove this function, the purpose is to understand whether a
+  // crash in PrefChangeRegistrar::~PrefChangeRegistrar() is caused by a
+  // PrefService already being dead. See crbug.com/373435.
+  virtual void BroadcastPrefServiceDestructionTrace(
+      const std::string& stack_trace) = 0;
 };
 
 #endif  // BASE_PREFS_PREF_NOTIFIER_H_

base/prefs/pref_notifier_impl.cc

@@ -94,6 +94,19 @@ void PrefNotifierImpl::OnInitializationCompleted(bool succeeded) {
   }
 }
 
+// TODO(battre): Delete this. See crbug.com/373435.
+void PrefNotifierImpl::BroadcastPrefServiceDestructionTrace(
+    const std::string& stack_trace) {
+  DCHECK(thread_checker_.CalledOnValidThread());
+  for (PrefObserverMap::iterator observer_iterator = pref_observers_.begin();
+       observer_iterator != pref_observers_.end();
+       ++observer_iterator) {
+    FOR_EACH_OBSERVER(PrefObserver,
+                      *(observer_iterator->second),
+                      SetPrefServiceDestructionTrace(stack_trace));
+  }
+}
+
 void PrefNotifierImpl::FireObservers(const std::string& path) {
   DCHECK(thread_checker_.CalledOnValidThread());
 

base/prefs/pref_notifier_impl.h

@@ -43,6 +43,9 @@ class BASE_PREFS_EXPORT PrefNotifierImpl
   // PrefNotifier overrides.
   virtual void OnPreferenceChanged(const std::string& pref_name) OVERRIDE;
   virtual void OnInitializationCompleted(bool succeeded) OVERRIDE;
+  // TODO(battre): Delete this. See crbug.com/373435.
+  virtual void BroadcastPrefServiceDestructionTrace(
+      const std::string& stack_trace) OVERRIDE;
 
   // A map from pref names to a list of observers. Observers get fired in the
   // order they are added. These should only be accessed externally for unit

base/prefs/pref_notifier_impl_unittest.cc

@@ -80,6 +80,9 @@ class PrefObserverMock : public PrefObserver {
   virtual ~PrefObserverMock() {}
 
   MOCK_METHOD2(OnPreferenceChanged, void(PrefService*, const std::string&));
+
+  // TODO(battre) Remove function. See crbug.com/373435.
+  MOCK_METHOD1(SetPrefServiceDestructionTrace, void(const std::string&));
 };
 
 // Test fixture class.

base/prefs/pref_observer.h

@@ -16,6 +16,10 @@ class PrefObserver {
  public:
   virtual void OnPreferenceChanged(PrefService* service,
                                    const std::string& pref_name) = 0;
+
+  // TODO(battre): Remove function (debugging tool for crbug.com/373435).
+  virtual void SetPrefServiceDestructionTrace(
+      const std::string& stack_trace) = 0;
 };
 
 #endif  // BASE_PREFS_PREF_OBSERVER_H_

base/prefs/pref_service.cc

@@ -7,6 +7,8 @@
 #include <algorithm>
 
 #include "base/bind.h"
+// TODO(battre): Delete this. See crbug.com/373435.
+#include "base/debug/stack_trace.h"
 #include "base/files/file_path.h"
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
@@ -59,6 +61,13 @@ PrefService::PrefService(
 PrefService::~PrefService() {
   DCHECK(CalledOnValidThread());
 
+  // TODO(battre): Remove the following code. It's purpose is to understand
+  // whether a crash in PrefChangeRegistrar::~PrefChangeRegistrar() is caused
+  // by a PrefService already being dead. See crbug.com/373435.
+  std::string stack_trace = base::debug::StackTrace().ToString();
+  static_cast<PrefNotifier*>(pref_notifier_.get())
+      ->BroadcastPrefServiceDestructionTrace(stack_trace);
+
   // Reset pointers so accesses after destruction reliably crash.
   pref_value_store_.reset();
   pref_registry_ = NULL;

base/prefs/pref_value_store_unittest.cc

@@ -24,6 +24,8 @@ class MockPrefNotifier : public PrefNotifier {
  public:
   MOCK_METHOD1(OnPreferenceChanged, void(const std::string&));
   MOCK_METHOD1(OnInitializationCompleted, void(bool));
+  // TODO(battre) Remove function. See crbug.com/373435.
+  MOCK_METHOD1(BroadcastPrefServiceDestructionTrace, void(const std::string&));
 };
 
 // Allows to capture sync model associator interaction.