diff --git a/dom/indexedDB/ActorsChild.cpp b/dom/indexedDB/ActorsChild.cpp index 5043d4265211..bebcbab12bea 100644 --- a/dom/indexedDB/ActorsChild.cpp +++ b/dom/indexedDB/ActorsChild.cpp @@ -56,6 +56,37 @@ namespace mozilla { namespace dom { namespace indexedDB { +/******************************************************************************* + * ThreadLocal + ******************************************************************************/ + +ThreadLocal::ThreadLocal(const nsID& aBackgroundChildLoggingId) + : mLoggingInfo(aBackgroundChildLoggingId, 1, -1, 1) + , mCurrentTransaction(0) +#ifdef DEBUG + , mOwningThread(PR_GetCurrentThread()) +#endif +{ + MOZ_ASSERT(mOwningThread); + + MOZ_COUNT_CTOR(mozilla::dom::indexedDB::ThreadLocal); +} + +ThreadLocal::~ThreadLocal() +{ + MOZ_COUNT_DTOR(mozilla::dom::indexedDB::ThreadLocal); +} + +#ifdef DEBUG + +void +ThreadLocal::AssertIsOnOwningThread() const +{ + MOZ_ASSERT(PR_GetCurrentThread() == mOwningThread); +} + +#endif // DEBUG + /******************************************************************************* * Helpers ******************************************************************************/ @@ -104,39 +135,40 @@ class MOZ_STACK_CLASS AutoSetCurrentTransaction MOZ_FINAL IDBTransaction* const mTransaction; IDBTransaction* mPreviousTransaction; - IDBTransaction** mThreadLocalSlot; + ThreadLocal* mThreadLocal; public: explicit AutoSetCurrentTransaction(IDBTransaction* aTransaction) : mTransaction(aTransaction) , mPreviousTransaction(nullptr) - , mThreadLocalSlot(nullptr) + , mThreadLocal(nullptr) { if (aTransaction) { BackgroundChildImpl::ThreadLocal* threadLocal = BackgroundChildImpl::GetThreadLocalForCurrentThread(); MOZ_ASSERT(threadLocal); - // Hang onto this location for resetting later. - mThreadLocalSlot = &threadLocal->mCurrentTransaction; + // Hang onto this for resetting later. + mThreadLocal = threadLocal->mIndexedDBThreadLocal; + MOZ_ASSERT(mThreadLocal); // Save the current value. - mPreviousTransaction = *mThreadLocalSlot; + mPreviousTransaction = mThreadLocal->GetCurrentTransaction(); // Set the new value. - *mThreadLocalSlot = aTransaction; + mThreadLocal->SetCurrentTransaction(aTransaction); } } ~AutoSetCurrentTransaction() { - MOZ_ASSERT_IF(mThreadLocalSlot, mTransaction); - - if (mThreadLocalSlot) { - MOZ_ASSERT(*mThreadLocalSlot == mTransaction); + MOZ_ASSERT_IF(mThreadLocal, mTransaction); + MOZ_ASSERT_IF(mThreadLocal, + mThreadLocal->GetCurrentTransaction() == mTransaction); + if (mThreadLocal) { // Reset old value. - *mThreadLocalSlot = mPreviousTransaction; + mThreadLocal->SetCurrentTransaction(mPreviousTransaction); } } @@ -589,6 +621,25 @@ DispatchErrorEvent(IDBRequest* aRequest, asct.emplace(aTransaction); } + if (transaction) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "Firing %s event with error 0x%x", + "IndexedDB %s: C T[%lld] R[%llu]: %s (0x%x)", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(aEvent, kErrorEventType), + aErrorCode); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Request[%llu]: " + "Firing %s event with error 0x%x", + "IndexedDB %s: C R[%llu]: %s (0x%x)", + IDB_LOG_ID_STRING(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(aEvent, kErrorEventType), + aErrorCode); + } + bool doDefault; nsresult rv = request->DispatchEvent(aEvent, &doDefault); if (NS_WARN_IF(NS_FAILED(rv))) { @@ -648,6 +699,22 @@ DispatchSuccessEvent(ResultHelper* aResultHelper, MOZ_ASSERT(aEvent); MOZ_ASSERT_IF(transaction, transaction->IsOpen()); + if (transaction) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "Firing %s event", + "IndexedDB %s: C T[%lld] R[%llu]: %s", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(aEvent, kSuccessEventType)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Request[%llu]: Firing %s event", + "IndexedDB %s: C R[%llu]: %s", + IDB_LOG_ID_STRING(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(aEvent, kSuccessEventType)); + } + bool dummy; nsresult rv = request->DispatchEvent(aEvent, &dummy); if (NS_WARN_IF(NS_FAILED(rv))) { @@ -1068,6 +1135,11 @@ BackgroundFactoryRequestChild::RecvBlocked(const uint64_t& aCurrentVersion) nsRefPtr kungFuDeathGrip = mRequest; + IDB_LOG_MARK("IndexedDB %s: Child Request[%llu]: Firing \"blocked\" event", + "IndexedDB %s: C R[%llu]: \"blocked\"", + IDB_LOG_ID_STRING(), + mRequest->LoggingSerialNumber()); + bool dummy; if (NS_FAILED(mRequest->DispatchEvent(blockedEvent, &dummy))) { NS_WARNING("Failed to dispatch event!"); @@ -1357,6 +1429,10 @@ BackgroundDatabaseChild::RecvVersionChange(const uint64_t& aOldVersion, return false; } + IDB_LOG_MARK("IndexedDB %s: Child : Firing \"versionchange\" event", + "IndexedDB %s: C: IDBDatabase \"versionchange\" event", + IDB_LOG_ID_STRING()); + bool dummy; if (NS_FAILED(mDatabase->DispatchEvent(versionChangeEvent, &dummy))) { NS_WARNING("Failed to dispatch event!"); diff --git a/dom/indexedDB/ActorsChild.h b/dom/indexedDB/ActorsChild.h index d77ff27db1b3..f93cbc89e842 100644 --- a/dom/indexedDB/ActorsChild.h +++ b/dom/indexedDB/ActorsChild.h @@ -5,6 +5,7 @@ #ifndef mozilla_dom_indexeddb_actorschild_h__ #define mozilla_dom_indexeddb_actorschild_h__ +#include "IDBTransaction.h" #include "js/RootingAPI.h" #include "mozilla/Attributes.h" #include "mozilla/dom/indexedDB/PBackgroundIDBCursorChild.h" @@ -12,6 +13,7 @@ #include "mozilla/dom/indexedDB/PBackgroundIDBFactoryChild.h" #include "mozilla/dom/indexedDB/PBackgroundIDBFactoryRequestChild.h" #include "mozilla/dom/indexedDB/PBackgroundIDBRequestChild.h" +#include "mozilla/dom/indexedDB/PBackgroundIDBSharedTypes.h" #include "mozilla/dom/indexedDB/PBackgroundIDBTransactionChild.h" #include "mozilla/dom/indexedDB/PBackgroundIDBVersionChangeTransactionChild.h" #include "nsAutoPtr.h" @@ -19,6 +21,7 @@ #include "nsTArray.h" class nsIEventTarget; +struct nsID; struct PRThread; namespace mozilla { @@ -38,13 +41,97 @@ class IDBFactory; class IDBMutableFile; class IDBOpenDBRequest; class IDBRequest; -class IDBTransaction; class Key; class PBackgroundIDBFileChild; class PermissionRequestChild; class PermissionRequestParent; class SerializedStructuredCloneReadInfo; +class ThreadLocal +{ + friend class nsAutoPtr; + friend class IDBFactory; + + LoggingInfo mLoggingInfo; + IDBTransaction* mCurrentTransaction; + +#ifdef DEBUG + PRThread* mOwningThread; +#endif + +public: + void + AssertIsOnOwningThread() const +#ifdef DEBUG + ; +#else + { } +#endif + + const LoggingInfo& + GetLoggingInfo() const + { + AssertIsOnOwningThread(); + + return mLoggingInfo; + } + + const nsID& + Id() const + { + AssertIsOnOwningThread(); + + return mLoggingInfo.backgroundChildLoggingId(); + } + + int64_t + NextTransactionSN(IDBTransaction::Mode aMode) + { + AssertIsOnOwningThread(); + MOZ_ASSERT(mLoggingInfo.nextTransactionSerialNumber() < INT64_MAX); + MOZ_ASSERT(mLoggingInfo.nextVersionChangeTransactionSerialNumber() > + INT64_MIN); + + if (aMode == IDBTransaction::VERSION_CHANGE) { + return mLoggingInfo.nextVersionChangeTransactionSerialNumber()--; + } + + return mLoggingInfo.nextTransactionSerialNumber()++; + } + + uint64_t + NextRequestSN() + { + AssertIsOnOwningThread(); + MOZ_ASSERT(mLoggingInfo.nextRequestSerialNumber() < UINT64_MAX); + + return mLoggingInfo.nextRequestSerialNumber()++; + } + + void + SetCurrentTransaction(IDBTransaction* aCurrentTransaction) + { + AssertIsOnOwningThread(); + + mCurrentTransaction = aCurrentTransaction; + } + + IDBTransaction* + GetCurrentTransaction() const + { + AssertIsOnOwningThread(); + + return mCurrentTransaction; + } + +private: + ThreadLocal(const nsID& aBackgroundChildLoggingId); + ~ThreadLocal(); + + ThreadLocal() MOZ_DELETE; + ThreadLocal(const ThreadLocal& aOther) MOZ_DELETE; +}; + class BackgroundFactoryChild MOZ_FINAL : public PBackgroundIDBFactoryChild { diff --git a/dom/indexedDB/ActorsParent.cpp b/dom/indexedDB/ActorsParent.cpp index 8944be1f04f0..22d693b15660 100644 --- a/dom/indexedDB/ActorsParent.cpp +++ b/dom/indexedDB/ActorsParent.cpp @@ -107,6 +107,7 @@ namespace { class Cursor; class Database; struct DatabaseActorInfo; +class DatabaseLoggingInfo; class DatabaseFile; class DatabaseOfflineStorage; class Factory; @@ -2553,17 +2554,14 @@ class DatabaseOperationBase : public nsRunnable , public mozIStorageProgressHandler { - // Uniquely tracks each operation for logging purposes. Only modified on the - // PBackground thread. - static uint64_t sNextSerialNumber; - protected: class AutoSetProgressHandler; typedef nsDataHashtable UniqueIndexTable; nsCOMPtr mOwningThread; - const uint64_t mSerialNumber; + const nsID mBackgroundChildLoggingId; + const uint64_t mLoggingSerialNumber; nsresult mResultCode; private: @@ -2610,10 +2608,16 @@ public: return mOperationMayProceed; } - uint64_t - SerialNumber() const + const nsID& + BackgroundChildLoggingId() const { - return mSerialNumber; + return mBackgroundChildLoggingId; + } + + uint64_t + LoggingSerialNumber() const + { + return mLoggingSerialNumber; } nsresult @@ -2632,9 +2636,11 @@ public: } protected: - DatabaseOperationBase() + DatabaseOperationBase(const nsID& aBackgroundChildLoggingId, + uint64_t aLoggingSerialNumber) : mOwningThread(NS_GetCurrentThread()) - , mSerialNumber(++sNextSerialNumber) + , mBackgroundChildLoggingId(aBackgroundChildLoggingId) + , mLoggingSerialNumber(aLoggingSerialNumber) , mResultCode(NS_OK) , mOperationMayProceed(true) , mActorDestroyed(false) @@ -2709,6 +2715,7 @@ class TransactionDatabaseOperationBase : public DatabaseOperationBase { nsRefPtr mTransaction; + const int64_t mTransactionLoggingSerialNumber; const bool mTransactionIsAborted; public: @@ -2736,7 +2743,11 @@ public: Cleanup(); protected: - explicit TransactionDatabaseOperationBase(TransactionBase* aTransaction); + explicit + TransactionDatabaseOperationBase(TransactionBase* aTransaction); + + TransactionDatabaseOperationBase(TransactionBase* aTransaction, + uint64_t aLoggingSerialNumber); virtual ~TransactionDatabaseOperationBase(); @@ -2779,17 +2790,29 @@ class Factory MOZ_FINAL // ActorDestroy called. static uint64_t sFactoryInstanceCount; + nsRefPtr mLoggingInfo; + DebugOnly mActorDestroyed; public: static already_AddRefed - Create(); + Create(const LoggingInfo& aLoggingInfo); + + DatabaseLoggingInfo* + GetLoggingInfo() const + { + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mLoggingInfo); + + return mLoggingInfo; + } NS_INLINE_DECL_THREADSAFE_REFCOUNTING(mozilla::dom::indexedDB::Factory) private: // Only constructed in Create(). - explicit Factory(); + explicit + Factory(already_AddRefed aLoggingInfo); // Reference counted. ~Factory(); @@ -2801,6 +2824,9 @@ private: virtual bool RecvDeleteMe() MOZ_OVERRIDE; + virtual bool + RecvIncrementLoggingRequestSerialNumber() MOZ_OVERRIDE; + virtual PBackgroundIDBFactoryRequestParent* AllocPBackgroundIDBFactoryRequestParent(const FactoryRequestParams& aParams) MOZ_OVERRIDE; @@ -2924,6 +2950,15 @@ public: return Manager()->Manager(); } + DatabaseLoggingInfo* + GetLoggingInfo() const + { + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mFactory); + + return mFactory->GetLoggingInfo(); + } + bool RegisterTransaction(TransactionBase* aTransaction); @@ -3130,6 +3165,7 @@ private: mModifiedAutoIncrementObjectStoreMetadataArray; const uint64_t mTransactionId; const nsCString mDatabaseId; + const int64_t mLoggingSerialNumber; uint64_t mActiveRequestCount; Atomic mInvalidatedOnAnyThread; Mode mMode; @@ -3248,6 +3284,21 @@ public: return mDatabase; } + DatabaseLoggingInfo* + GetLoggingInfo() const + { + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mDatabase); + + return mDatabase->GetLoggingInfo(); + } + + int64_t + LoggingSerialNumber() const + { + return mLoggingSerialNumber; + } + bool IsAborted() const { @@ -3297,8 +3348,7 @@ public: Invalidate(); protected: - TransactionBase(Database* aDatabase, - Mode aMode); + TransactionBase(Database* aDatabase, Mode aMode); virtual ~TransactionBase(); @@ -3420,13 +3470,7 @@ class TransactionBase::CommitOp MOZ_FINAL nsresult mResultCode; private: - CommitOp(TransactionBase* aTransaction, - nsresult aResultCode) - : mTransaction(aTransaction) - , mResultCode(aResultCode) - { - MOZ_ASSERT(aTransaction); - } + CommitOp(TransactionBase* aTransaction, nsresult aResultCode); ~CommitOp() { } @@ -3670,8 +3714,8 @@ class NormalTransaction MOZ_FINAL private: // This constructor is only called by Database. NormalTransaction(Database* aDatabase, - nsTArray>& aObjectStores, - TransactionBase::Mode aMode); + TransactionBase::Mode aMode, + nsTArray>& aObjectStores); // Reference counted. ~NormalTransaction() @@ -4133,9 +4177,11 @@ class OpenDatabaseOp::VersionChangeOp MOZ_FINAL uint64_t mPreviousVersion; private: - explicit VersionChangeOp(OpenDatabaseOp* aOpenDatabaseOp) + explicit + VersionChangeOp(OpenDatabaseOp* aOpenDatabaseOp) : TransactionDatabaseOperationBase( - aOpenDatabaseOp->mVersionChangeTransaction) + aOpenDatabaseOp->mVersionChangeTransaction, + aOpenDatabaseOp->LoggingSerialNumber()) , mOpenDatabaseOp(aOpenDatabaseOp) , mRequestedVersion(aOpenDatabaseOp->mRequestedVersion) , mPreviousVersion(aOpenDatabaseOp->mMetadata->mCommonMetadata.version()) @@ -4214,8 +4260,11 @@ class DeleteDatabaseOp::VersionChangeOp MOZ_FINAL nsRefPtr mDeleteDatabaseOp; private: - explicit VersionChangeOp(DeleteDatabaseOp* aDeleteDatabaseOp) - : mDeleteDatabaseOp(aDeleteDatabaseOp) + explicit + VersionChangeOp(DeleteDatabaseOp* aDeleteDatabaseOp) + : DatabaseOperationBase(aDeleteDatabaseOp->BackgroundChildLoggingId(), + aDeleteDatabaseOp->LoggingSerialNumber()) + , mDeleteDatabaseOp(aDeleteDatabaseOp) { MOZ_ASSERT(aDeleteDatabaseOp); MOZ_ASSERT(!aDeleteDatabaseOp->mDatabaseDirectoryPath.IsEmpty()); @@ -4991,7 +5040,7 @@ private: * Other class declarations ******************************************************************************/ -struct DatabaseActorInfo +struct DatabaseActorInfo MOZ_FINAL { friend class nsAutoPtr; @@ -5021,6 +5070,60 @@ private: } }; +class DatabaseLoggingInfo MOZ_FINAL +{ +#ifdef DEBUG + // Just for potential warnings. + friend class Factory; +#endif + + LoggingInfo mLoggingInfo; + +public: + DatabaseLoggingInfo(const LoggingInfo& aLoggingInfo) + : mLoggingInfo(aLoggingInfo) + { + AssertIsOnBackgroundThread(); + } + + const nsID& + Id() const + { + AssertIsOnBackgroundThread(); + + return mLoggingInfo.backgroundChildLoggingId(); + } + + int64_t + NextTransactionSN(IDBTransaction::Mode aMode) + { + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mLoggingInfo.nextTransactionSerialNumber() < INT64_MAX); + MOZ_ASSERT(mLoggingInfo.nextVersionChangeTransactionSerialNumber() > + INT64_MIN); + + if (aMode == IDBTransaction::VERSION_CHANGE) { + return mLoggingInfo.nextVersionChangeTransactionSerialNumber()--; + } + + return mLoggingInfo.nextTransactionSerialNumber()++; + } + + uint64_t + NextRequestSN() + { + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mLoggingInfo.nextRequestSerialNumber() < UINT64_MAX); + + return mLoggingInfo.nextRequestSerialNumber()++; + } + + NS_INLINE_DECL_REFCOUNTING(DatabaseLoggingInfo) + +private: + ~DatabaseLoggingInfo(); +}; + class NonMainThreadHackBlobImpl MOZ_FINAL : public FileImplFile { @@ -5524,6 +5627,11 @@ StaticRefPtr gStartTransactionRunnable; StaticRefPtr gTransactionThreadPool; +typedef nsDataHashtable + DatabaseLoggingInfoHashtable; + +StaticAutoPtr gLoggingInfoHashtable; + #ifdef DEBUG StaticRefPtr gDEBUGThreadSlower; @@ -5537,7 +5645,7 @@ StaticRefPtr gDEBUGThreadSlower; ******************************************************************************/ PBackgroundIDBFactoryParent* -AllocPBackgroundIDBFactoryParent() +AllocPBackgroundIDBFactoryParent(const LoggingInfo& aLoggingInfo) { AssertIsOnBackgroundThread(); @@ -5545,12 +5653,15 @@ AllocPBackgroundIDBFactoryParent() return nullptr; } - nsRefPtr actor = Factory::Create(); + nsRefPtr actor = Factory::Create(aLoggingInfo); + MOZ_ASSERT(actor); + return actor.forget().take(); } bool -RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor) +RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor, + const LoggingInfo& /* aLoggingInfo */) { AssertIsOnBackgroundThread(); MOZ_ASSERT(aActor); @@ -5727,14 +5838,27 @@ FullDatabaseMetadata::Duplicate() const return newMetadata.forget(); } +DatabaseLoggingInfo::~DatabaseLoggingInfo() +{ + MOZ_ASSERT(gLoggingInfoHashtable); + + const nsID& backgroundChildLoggingId = + mLoggingInfo.backgroundChildLoggingId(); + + MOZ_ASSERT(gLoggingInfoHashtable->Get(backgroundChildLoggingId) == this); + + gLoggingInfoHashtable->Remove(backgroundChildLoggingId); +} + /******************************************************************************* * Factory ******************************************************************************/ uint64_t Factory::sFactoryInstanceCount = 0; -Factory::Factory() - : mActorDestroyed(false) +Factory::Factory(already_AddRefed aLoggingInfo) + : mLoggingInfo(Move(aLoggingInfo)) + , mActorDestroyed(false) { AssertIsOnBackgroundThread(); MOZ_ASSERT(!QuotaClient::IsShuttingDownOnNonMainThread()); @@ -5742,12 +5866,13 @@ Factory::Factory() Factory::~Factory() { + MOZ_ASSERT(!mLoggingInfo); MOZ_ASSERT(mActorDestroyed); } // static already_AddRefed -Factory::Create() +Factory::Create(const LoggingInfo& aLoggingInfo) { AssertIsOnBackgroundThread(); MOZ_ASSERT(!QuotaClient::IsShuttingDownOnNonMainThread()); @@ -5770,6 +5895,9 @@ Factory::Create() MOZ_ASSERT(!gStartTransactionRunnable); gStartTransactionRunnable = new nsRunnable(); + MOZ_ASSERT(!gLoggingInfoHashtable); + gLoggingInfoHashtable = new DatabaseLoggingInfoHashtable(); + #ifdef DEBUG if (kDEBUGThreadPriority != nsISupportsPriority::PRIORITY_NORMAL) { NS_WARNING("PBackground thread debugging enabled, priority has been " @@ -5795,7 +5923,29 @@ Factory::Create() #endif // DEBUG } - nsRefPtr actor = new Factory(); + nsRefPtr loggingInfo = + gLoggingInfoHashtable->Get(aLoggingInfo.backgroundChildLoggingId()); + if (loggingInfo) { + MOZ_ASSERT(aLoggingInfo.backgroundChildLoggingId() == loggingInfo->Id()); +#if !DISABLE_ASSERTS_FOR_FUZZING + NS_WARN_IF_FALSE(aLoggingInfo.nextTransactionSerialNumber() == + loggingInfo->mLoggingInfo.nextTransactionSerialNumber(), + "NextTransactionSerialNumber doesn't match!"); + NS_WARN_IF_FALSE(aLoggingInfo.nextVersionChangeTransactionSerialNumber() == + loggingInfo->mLoggingInfo. + nextVersionChangeTransactionSerialNumber(), + "NextVersionChangeTransactionSerialNumber doesn't match!"); + NS_WARN_IF_FALSE(aLoggingInfo.nextRequestSerialNumber() == + loggingInfo->mLoggingInfo.nextRequestSerialNumber(), + "NextRequestSerialNumber doesn't match!"); +#endif // !DISABLE_ASSERTS_FOR_FUZZING + } else { + loggingInfo = new DatabaseLoggingInfo(aLoggingInfo); + gLoggingInfoHashtable->Put(aLoggingInfo.backgroundChildLoggingId(), + loggingInfo); + } + + nsRefPtr actor = new Factory(loggingInfo.forget()); sFactoryInstanceCount++; @@ -5810,8 +5960,14 @@ Factory::ActorDestroy(ActorDestroyReason aWhy) mActorDestroyed = true; + mLoggingInfo = nullptr; + // Clean up if there are no more instances. if (!(--sFactoryInstanceCount)) { + MOZ_ASSERT(gLoggingInfoHashtable); + MOZ_ASSERT(!gLoggingInfoHashtable->Count()); + gLoggingInfoHashtable = nullptr; + MOZ_ASSERT(gStartTransactionRunnable); gStartTransactionRunnable = nullptr; @@ -5853,6 +6009,16 @@ Factory::RecvDeleteMe() return PBackgroundIDBFactoryParent::Send__delete__(this); } +bool +Factory::RecvIncrementLoggingRequestSerialNumber() +{ + AssertIsOnBackgroundThread(); + MOZ_ASSERT(mLoggingInfo); + + mLoggingInfo->NextRequestSN(); + return true; +} + PBackgroundIDBFactoryRequestParent* Factory::AllocPBackgroundIDBFactoryRequestParent( const FactoryRequestParams& aParams) @@ -6077,7 +6243,7 @@ Database::Invalidate() mInvalidated = true; - if (!mActorDestroyed) { + if (mActorWasAlive && !mActorDestroyed) { unused << SendInvalidate(); } @@ -6329,6 +6495,15 @@ Database::AllocPBackgroundIDBTransactionParent( for (uint32_t nameIndex = 0; nameIndex < nameCount; nameIndex++) { const nsString& name = aObjectStoreNames[nameIndex]; + + if (nameIndex) { + // Make sure that this name is sorted properly and not a duplicate. + if (NS_WARN_IF(name <= aObjectStoreNames[nameIndex - 1])) { + ASSERT_UNLESS_FUZZING(); + return nullptr; + } + } + const uint32_t oldLength = fallibleObjectStores.Length(); Closure closure(name, fallibleObjectStores); @@ -6343,7 +6518,7 @@ Database::AllocPBackgroundIDBTransactionParent( infallibleObjectStores.SwapElements(fallibleObjectStores); nsRefPtr transaction = - new NormalTransaction(this, infallibleObjectStores, aMode); + new NormalTransaction(this, aMode, infallibleObjectStores); MOZ_ASSERT(infallibleObjectStores.IsEmpty()); @@ -6372,13 +6547,13 @@ Database::RecvPBackgroundIDBTransactionConstructor( auto* transaction = static_cast(aActor); // Add a placeholder for this transaction immediately. - gTransactionThreadPool->Dispatch(transaction->TransactionId(), - mMetadata->mDatabaseId, - aObjectStoreNames, - aMode, - gStartTransactionRunnable, - /* aFinish */ false, - /* aFinishCallback */ nullptr); + gTransactionThreadPool->Start(transaction->TransactionId(), + mMetadata->mDatabaseId, + aObjectStoreNames, + aMode, + GetLoggingInfo()->Id(), + transaction->LoggingSerialNumber(), + gStartTransactionRunnable); transaction->SetActive(); @@ -6472,11 +6647,11 @@ Database::RecvClose() * TransactionBase ******************************************************************************/ -TransactionBase::TransactionBase(Database* aDatabase, - Mode aMode) +TransactionBase::TransactionBase(Database* aDatabase, Mode aMode) : mDatabase(aDatabase) , mTransactionId(gTransactionThreadPool->NextTransactionId()) , mDatabaseId(aDatabase->Id()) + , mLoggingSerialNumber(aDatabase->GetLoggingInfo()->NextTransactionSN(aMode)) , mActiveRequestCount(0) , mInvalidatedOnAnyThread(false) , mMode(aMode) @@ -6492,6 +6667,8 @@ TransactionBase::TransactionBase(Database* aDatabase, { AssertIsOnBackgroundThread(); MOZ_ASSERT(aDatabase); + MOZ_ASSERT(mTransactionId); + MOZ_ASSERT(mLoggingSerialNumber); } TransactionBase::~TransactionBase() @@ -7621,8 +7798,8 @@ TransactionBase::ReleaseBackgroundThreadObjects() NormalTransaction::NormalTransaction( Database* aDatabase, - nsTArray>& aObjectStores, - TransactionBase::Mode aMode) + TransactionBase::Mode aMode, + nsTArray>& aObjectStores) : TransactionBase(aDatabase, aMode) { AssertIsOnBackgroundThread(); @@ -9919,8 +10096,6 @@ DatabaseOfflineStorage::Invalidate() NS_IMPL_ISUPPORTS(CompressDataBlobsFunction, mozIStorageFunction) NS_IMPL_ISUPPORTS(EncodeKeysFunction, mozIStorageFunction) -uint64_t DatabaseOperationBase::sNextSerialNumber = 0; - // static void DatabaseOperationBase::GetBindingClauseForKeyRange( @@ -10329,7 +10504,9 @@ FactoryOp::FactoryOp(Factory* aFactory, already_AddRefed aContentParent, const CommonFactoryRequestParams& aCommonParams, bool aDeleting) - : mFactory(aFactory) + : DatabaseOperationBase(aFactory->GetLoggingInfo()->Id(), + aFactory->GetLoggingInfo()->NextRequestSN()) + , mFactory(aFactory) , mContentParent(Move(aContentParent)) , mCommonParams(aCommonParams) , mState(State_Initial) @@ -11076,7 +11253,7 @@ OpenDatabaseOp::DoDatabaseWork() MOZ_ASSERT(mState == State_DatabaseWorkOpen); PROFILER_LABEL("IndexedDB", - "OpenDatabaseHelper::DoDatabaseWork", + "OpenDatabaseOp::DoDatabaseWork", js::ProfileEntry::Category::STORAGE); if (NS_WARN_IF(QuotaClient::IsShuttingDownOnNonMainThread()) || @@ -11649,6 +11826,8 @@ OpenDatabaseOp::DispatchToWorkThread() AssertIsOnOwningThread(); MOZ_ASSERT(mState == State_WaitingForTransactionsToComplete); MOZ_ASSERT(mVersionChangeTransaction); + MOZ_ASSERT(mVersionChangeTransaction->GetMode() == + IDBTransaction::VERSION_CHANGE); MOZ_ASSERT(mMaybeBlockedDatabases.IsEmpty()); if (IsActorDestroyed()) { @@ -11661,15 +11840,20 @@ OpenDatabaseOp::DispatchToWorkThread() // Intentionally empty. nsTArray objectStoreNames; + const int64_t loggingSerialNumber = + mVersionChangeTransaction->LoggingSerialNumber(); + const nsID& backgroundChildLoggingId = + mVersionChangeTransaction->GetLoggingInfo()->Id(); + nsRefPtr versionChangeOp = new VersionChangeOp(this); - gTransactionThreadPool->Dispatch(mVersionChangeTransaction->TransactionId(), - mVersionChangeTransaction->DatabaseId(), - objectStoreNames, - mVersionChangeTransaction->GetMode(), - versionChangeOp, - /* aFinish */ false, - /* aFinishCallback */ nullptr); + gTransactionThreadPool->Start(mVersionChangeTransaction->TransactionId(), + mVersionChangeTransaction->DatabaseId(), + objectStoreNames, + mVersionChangeTransaction->GetMode(), + backgroundChildLoggingId, + loggingSerialNumber, + versionChangeOp); mVersionChangeTransaction->SetActive(); @@ -12109,7 +12293,7 @@ VersionChangeOp::DoDatabaseWork(TransactionBase* aTransaction) } PROFILER_LABEL("IndexedDB", - "VersionChangeOp::DoDatabaseWork", + "OpenDatabaseOp::VersionChangeOp::DoDatabaseWork", js::ProfileEntry::Category::STORAGE); mozIStorageConnection* connection = aTransaction->Connection(); @@ -12797,10 +12981,27 @@ VersionChangeOp::Run() TransactionDatabaseOperationBase::TransactionDatabaseOperationBase( TransactionBase* aTransaction) - : mTransaction(aTransaction) + : DatabaseOperationBase(aTransaction->GetLoggingInfo()->Id(), + aTransaction->GetLoggingInfo()->NextRequestSN()) + , mTransaction(aTransaction) + , mTransactionLoggingSerialNumber(aTransaction->LoggingSerialNumber()) , mTransactionIsAborted(aTransaction->IsAborted()) { MOZ_ASSERT(aTransaction); + MOZ_ASSERT(LoggingSerialNumber()); +} + +TransactionDatabaseOperationBase::TransactionDatabaseOperationBase( + TransactionBase* aTransaction, + uint64_t aLoggingSerialNumber) + : DatabaseOperationBase(aTransaction->GetLoggingInfo()->Id(), + aLoggingSerialNumber) + , mTransaction(aTransaction) + , mTransactionLoggingSerialNumber(aTransaction->LoggingSerialNumber()) + , mTransactionIsAborted(aTransaction->IsAborted()) +{ + MOZ_ASSERT(aTransaction); + MOZ_ASSERT(LoggingSerialNumber()); } TransactionDatabaseOperationBase::~TransactionDatabaseOperationBase() @@ -12842,6 +13043,10 @@ TransactionDatabaseOperationBase::RunOnTransactionThread() MOZ_ASSERT(mTransaction); MOZ_ASSERT(NS_SUCCEEDED(mResultCode)); + PROFILER_LABEL("IndexedDB", + "TransactionDatabaseOperationBase::RunOnTransactionThread", + js::ProfileEntry::Category::STORAGE); + // There are several cases where we don't actually have to to any work here. if (mTransactionIsAborted) { @@ -12868,7 +13073,22 @@ TransactionDatabaseOperationBase::RunOnTransactionThread() if (NS_WARN_IF(NS_FAILED(rv))) { mResultCode = rv; } else { + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld] Request[%llu]: " + "Beginning database work", + "IndexedDB %s: P T[%lld] R[%llu]: DB Start", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mTransactionLoggingSerialNumber, + mLoggingSerialNumber); + rv = DoDatabaseWork(mTransaction); + + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld] Request[%llu]: " + "Finished database work", + "IndexedDB %s: P T[%lld] R[%llu]: DB End", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mTransactionLoggingSerialNumber, + mLoggingSerialNumber); + if (NS_FAILED(rv)) { mResultCode = rv; } @@ -12950,6 +13170,18 @@ TransactionDatabaseOperationBase::Run() return NS_OK; } +TransactionBase:: + +CommitOp::CommitOp(TransactionBase* aTransaction, nsresult aResultCode) + : DatabaseOperationBase(aTransaction->GetLoggingInfo()->Id(), + aTransaction->GetLoggingInfo()->NextRequestSN()) + , mTransaction(aTransaction) + , mResultCode(aResultCode) +{ + MOZ_ASSERT(aTransaction); + MOZ_ASSERT(LoggingSerialNumber()); +} + nsresult TransactionBase:: CommitOp::WriteAutoIncrementCounts() @@ -13055,6 +13287,13 @@ CommitOp::Run() AssertIsOnTransactionThread(); + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld] Request[%llu]: " + "Beginning database work", + "IndexedDB %s: P T[%lld] R[%llu]: DB Start", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mTransaction->LoggingSerialNumber(), + mLoggingSerialNumber); + if (NS_SUCCEEDED(mResultCode) && mTransaction->mUpdateFileRefcountFunction) { mResultCode = mTransaction-> mUpdateFileRefcountFunction->WillCommit(connection); @@ -13095,6 +13334,13 @@ CommitOp::Run() mTransaction->ReleaseTransactionThreadObjects(); + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld] Request[%llu]: " + "Finished database work", + "IndexedDB %s: P T[%lld] R[%llu]: DB End", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mTransaction->LoggingSerialNumber(), + mLoggingSerialNumber); + return NS_OK; } @@ -13121,13 +13367,14 @@ CommitOp::TransactionFinishedAfterUnblock() AssertIsOnBackgroundThread(); MOZ_ASSERT(mTransaction); - PROFILER_LABEL("IndexedDB", - "CommitOp::TransactionFinishedAfterUnblock", - js::ProfileEntry::Category::STORAGE); - - IDB_PROFILER_MARK("IndexedDB Transaction %llu: Complete (rv = %lu)", - "IDBTransaction[%llu] MT Complete", - mTransaction->TransactionId(), mResultCode); + if (!mTransaction->IsActorDestroyed()) { + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld]: " + "Finished with result 0x%x", + "IndexedDB %s: P T[%lld]: Transaction finished (0x%x)", + IDB_LOG_ID_STRING(mTransaction->GetLoggingInfo()->Id()), + mTransaction->LoggingSerialNumber(), + mResultCode); + } mTransaction->ReleaseBackgroundThreadObjects(); @@ -16604,6 +16851,10 @@ OpenOp::DoDatabaseWork(TransactionBase* aTransaction) MOZ_ASSERT(mCursor->mKey.IsUnset()); MOZ_ASSERT(mCursor->mRangeKey.IsUnset()); + PROFILER_LABEL("IndexedDB", + "Cursor::OpenOp::DoDatabaseWork", + js::ProfileEntry::Category::STORAGE); + nsresult rv; switch (mCursor->mType) { diff --git a/dom/indexedDB/ActorsParent.h b/dom/indexedDB/ActorsParent.h index 75f1417f96d4..ad42be4ee930 100644 --- a/dom/indexedDB/ActorsParent.h +++ b/dom/indexedDB/ActorsParent.h @@ -7,6 +7,7 @@ template struct already_AddRefed; class nsCString; +struct nsID; class nsIPrincipal; class nsPIDOMWindow; @@ -23,14 +24,16 @@ class Client; namespace indexedDB { +class LoggingInfo; class PBackgroundIDBFactoryParent; class PIndexedDBPermissionRequestParent; PBackgroundIDBFactoryParent* -AllocPBackgroundIDBFactoryParent(); +AllocPBackgroundIDBFactoryParent(const LoggingInfo& aLoggingInfo); bool -RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor); +RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor, + const LoggingInfo& aLoggingInfo); bool DeallocPBackgroundIDBFactoryParent(PBackgroundIDBFactoryParent* aActor); diff --git a/dom/indexedDB/IDBCursor.cpp b/dom/indexedDB/IDBCursor.cpp index e12af8154b76..6e9842607f31 100644 --- a/dom/indexedDB/IDBCursor.cpp +++ b/dom/indexedDB/IDBCursor.cpp @@ -426,36 +426,41 @@ IDBCursor::Continue(JSContext* aCx, } } + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + mRequest->SetLoggingSerialNumber(requestSerialNumber); + + if (mType == Type_ObjectStore || mType == Type_ObjectStoreKey) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "cursor(%s).continue(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.continue()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(mSourceObjectStore), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(key)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "index(%s).cursor(%s).continue(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.continue()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(mSourceIndex->ObjectStore()), + IDB_LOG_STRINGIFY(mSourceIndex), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(key)); + } + mBackgroundActor->SendContinueInternal(ContinueParams(key)); mContinueCalled = true; - -#ifdef IDB_PROFILER_USE_MARKS - if (mType == Type_ObjectStore || mType == Type_ObjectStoreKey) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).cursor(%s)." - "continue(%s)", - "IDBRequest[%llu] MT IDBCursor.continue()", - Request()->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(mSourceObjectStore), - IDB_PROFILER_STRING(mDirection), - key.IsUnset() ? "" : IDB_PROFILER_STRING(key)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "cursor(%s).continue(%s)", - "IDBRequest[%llu] MT IDBCursor.continue()", - Request()->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(mSourceIndex->ObjectStore()), - IDB_PROFILER_STRING(mSourceIndex), - IDB_PROFILER_STRING(mDirection), - key.IsUnset() ? "" : IDB_PROFILER_STRING(key)); - } -#endif } void @@ -478,36 +483,41 @@ IDBCursor::Advance(uint32_t aCount, ErrorResult &aRv) return; } + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + mRequest->SetLoggingSerialNumber(requestSerialNumber); + + if (mType == Type_ObjectStore || mType == Type_ObjectStoreKey) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "cursor(%s).advance(%ld)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.advance()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(mSourceObjectStore), + IDB_LOG_STRINGIFY(mDirection), + aCount); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "index(%s).cursor(%s).advance(%ld)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.advance()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(mSourceIndex->ObjectStore()), + IDB_LOG_STRINGIFY(mSourceIndex), + IDB_LOG_STRINGIFY(mDirection), + aCount); + } + mBackgroundActor->SendContinueInternal(AdvanceParams(aCount)); mContinueCalled = true; - -#ifdef IDB_PROFILER_USE_MARKS - { - if (mType == Type_ObjectStore || mType == Type_ObjectStoreKey) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "cursor(%s).advance(%ld)", - "IDBRequest[%llu] MT IDBCursor.advance()", - Request()->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(mSourceObjectStore), - IDB_PROFILER_STRING(mDirection), aCount); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "index(%s).cursor(%s).advance(%ld)", - "IDBRequest[%llu] MT IDBCursor.advance()", - Request()->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(mSourceIndex->ObjectStore()), - IDB_PROFILER_STRING(mSourceIndex), - IDB_PROFILER_STRING(mDirection), aCount); - } - } -#endif } already_AddRefed @@ -563,7 +573,12 @@ IDBCursor::Update(JSContext* aCx, JS::Handle aValue, return nullptr; } - request = objectStore->Put(aCx, aValue, JS::UndefinedHandleValue, aRv); + request = objectStore->AddOrPut(aCx, + aValue, + /* aKey */ JS::UndefinedHandleValue, + /* aOverwrite */ true, + /* aFromCursor */ true, + aRv); if (aRv.Failed()) { return nullptr; } @@ -575,7 +590,12 @@ IDBCursor::Update(JSContext* aCx, JS::Handle aValue, return nullptr; } - request = objectStore->Put(aCx, aValue, keyVal, aRv); + request = objectStore->AddOrPut(aCx, + aValue, + keyVal, + /* aOverwrite */ true, + /* aFromCursor */ true, + aRv); if (aRv.Failed()) { return nullptr; } @@ -583,37 +603,34 @@ IDBCursor::Update(JSContext* aCx, JS::Handle aValue, request->SetSource(this); -#ifdef IDB_PROFILER_USE_MARKS - { - uint64_t requestSerial = request->GetSerialNumber(); - if (mType == Type_ObjectStore) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "cursor(%s).update(%s)", - "IDBRequest[%llu] MT IDBCursor.update()", - requestSerial, - IDB_PROFILER_STRING(mTransaction->Database()), - IDB_PROFILER_STRING(mTransaction), - IDB_PROFILER_STRING(objectStore), - IDB_PROFILER_STRING(mDirection), - mObjectStore->HasValidKeyPath() ? "" : - IDB_PROFILER_STRING(primaryKey)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "index(%s).cursor(%s).update(%s)", - "IDBRequest[%llu] MT IDBCursor.update()", - requestSerial, - IDB_PROFILER_STRING(mTransaction->Database()), - IDB_PROFILER_STRING(mTransaction), - IDB_PROFILER_STRING(objectStore), - IDB_PROFILER_STRING(mSourceIndex), - IDB_PROFILER_STRING(mDirection), - mObjectStore->HasValidKeyPath() ? "" : - IDB_PROFILER_STRING(primaryKey)); - } + if (mType == Type_ObjectStore) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "cursor(%s).update(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.update()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(objectStore), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(objectStore, primaryKey)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "index(%s).cursor(%s).update(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.update()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(objectStore), + IDB_LOG_STRINGIFY(mSourceIndex), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(objectStore, primaryKey)); } -#endif return request.forget(); } @@ -658,44 +675,42 @@ IDBCursor::Delete(JSContext* aCx, ErrorResult& aRv) return nullptr; } - nsRefPtr request = objectStore->Delete(aCx, key, aRv); + nsRefPtr request = + objectStore->DeleteInternal(aCx, key, /* aFromCursor */ true, aRv); if (aRv.Failed()) { return nullptr; } request->SetSource(this); -#ifdef IDB_PROFILER_USE_MARKS - { - uint64_t requestSerial = request->GetSerialNumber(); - if (mType == Type_ObjectStore) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "cursor(%s).delete(%s)", - "IDBRequest[%llu] MT IDBCursor.delete()", - requestSerial, - IDB_PROFILER_STRING(mTransaction->Database()), - IDB_PROFILER_STRING(mTransaction), - IDB_PROFILER_STRING(objectStore), - IDB_PROFILER_STRING(mDirection), - mObjectStore->HasValidKeyPath() ? "" : - IDB_PROFILER_STRING(primaryKey)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "index(%s).cursor(%s).delete(%s)", - "IDBRequest[%llu] MT IDBCursor.delete()", - requestSerial, - IDB_PROFILER_STRING(mTransaction->Database()), - IDB_PROFILER_STRING(mTransaction), - IDB_PROFILER_STRING(objectStore), - IDB_PROFILER_STRING(mSourceIndex), - IDB_PROFILER_STRING(mDirection), - mObjectStore->HasValidKeyPath() ? "" : - IDB_PROFILER_STRING(primaryKey)); - } + if (mType == Type_ObjectStore) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "cursor(%s).delete(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.delete()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(objectStore), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(objectStore, primaryKey)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "index(%s).cursor(%s).delete(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBCursor.delete()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(objectStore), + IDB_LOG_STRINGIFY(mSourceIndex), + IDB_LOG_STRINGIFY(mDirection), + IDB_LOG_STRINGIFY(objectStore, primaryKey)); } -#endif return request.forget(); } diff --git a/dom/indexedDB/IDBDatabase.cpp b/dom/indexedDB/IDBDatabase.cpp index ed7647642c78..63b0d53173d3 100644 --- a/dom/indexedDB/IDBDatabase.cpp +++ b/dom/indexedDB/IDBDatabase.cpp @@ -507,12 +507,20 @@ IDBDatabase::CreateObjectStore( transaction->CreateObjectStore(*newSpec); MOZ_ASSERT(objectStore); - IDB_PROFILER_MARK("IndexedDB Pseudo-request: " - "database(%s).transaction(%s).createObjectStore(%s)", - "MT IDBDatabase.createObjectStore()", - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aTransaction), - IDB_PROFILER_STRING(objectStore)); + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).createObjectStore(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: " + "IDBDatabase.createObjectStore()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(objectStore)); return objectStore.forget(); } @@ -560,12 +568,20 @@ IDBDatabase::DeleteObjectStore(const nsAString& aName, ErrorResult& aRv) return; } - IDB_PROFILER_MARK("IndexedDB Pseudo-request: " - "database(%s).transaction(%s).deleteObjectStore(\"%s\")", - "MT IDBDatabase.deleteObjectStore()", - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(transaction), - NS_ConvertUTF16toUTF8(aName).get()); + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).deleteObjectStore(\"%s\")", + "IndexedDB %s: C T[%lld] R[%llu]: " + "IDBDatabase.deleteObjectStore()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(transaction), + NS_ConvertUTF16toUTF8(aName).get()); } already_AddRefed @@ -670,6 +686,14 @@ IDBDatabase::Transaction(const Sequence& aStoreNames, BackgroundTransactionChild* actor = new BackgroundTransactionChild(transaction); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld]: " + "database(%s).transaction(%s)", + "IndexedDB %s: C T[%lld]: IDBDatabase.transaction()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(transaction)); + MOZ_ALWAYS_TRUE( mBackgroundActor->SendPBackgroundIDBTransactionConstructor(actor, sortedStoreNames, @@ -677,11 +701,6 @@ IDBDatabase::Transaction(const Sequence& aStoreNames, transaction->SetBackgroundActor(actor); - IDB_PROFILER_MARK("IndexedDB Transaction %llu: database(%s).transaction(%s)", - "IDBTransaction[%llu] MT Started", - transaction->GetSerialNumber(), IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(transaction)); - return transaction.forget(); } @@ -723,6 +742,8 @@ IDBDatabase::CreateMutableFile(const nsAString& aName, type = aType.Value(); } + mFactory->IncrementParentLoggingRequestSerialNumber(); + aRv = CreateFileHelper::CreateAndDispatch(this, request, aName, type); if (NS_WARN_IF(aRv.Failed())) { return nullptr; diff --git a/dom/indexedDB/IDBFactory.cpp b/dom/indexedDB/IDBFactory.cpp index be9fccb8041b..2019b446f3c9 100644 --- a/dom/indexedDB/IDBFactory.cpp +++ b/dom/indexedDB/IDBFactory.cpp @@ -6,6 +6,7 @@ #include "IDBFactory.h" +#include "BackgroundChildImpl.h" #include "IDBRequest.h" #include "IndexedDatabaseManager.h" #include "mozilla/ErrorResult.h" @@ -21,7 +22,9 @@ #include "nsIIPCBackgroundChildCreateCallback.h" #include "nsILoadContext.h" #include "nsIPrincipal.h" +#include "nsIUUIDGenerator.h" #include "nsIWebNavigation.h" +#include "nsServiceManagerUtils.h" #include "ProfilerHelpers.h" #include "ReportInternalError.h" @@ -76,10 +79,14 @@ class IDBFactory::BackgroundCreateCallback MOZ_FINAL : public nsIIPCBackgroundChildCreateCallback { nsRefPtr mFactory; + LoggingInfo mLoggingInfo; public: - explicit BackgroundCreateCallback(IDBFactory* aFactory) - : mFactory(aFactory) + explicit + BackgroundCreateCallback(IDBFactory* aFactory, + const LoggingInfo& aLoggingInfo) + : mFactory(aFactory) + , mLoggingInfo(aLoggingInfo) { MOZ_ASSERT(aFactory); } @@ -306,6 +313,15 @@ IDBFactory::SetBackgroundActor(BackgroundFactoryChild* aBackgroundActor) mBackgroundActor = aBackgroundActor; } +void +IDBFactory::IncrementParentLoggingRequestSerialNumber() +{ + AssertIsOnOwningThread(); + MOZ_ASSERT(mBackgroundActor); + + mBackgroundActor->SendIncrementLoggingRequestSerialNumber(); +} + already_AddRefed IDBFactory::Open(const nsAString& aName, uint64_t aVersion, @@ -501,27 +517,44 @@ IDBFactory::OpenInternal(nsIPrincipal* aPrincipal, params = OpenDatabaseRequestParams(commonParams); } - if (!mBackgroundActor) { - // If another consumer has already created a background actor for this - // thread then we can start this request immediately. - if (PBackgroundChild* bgActor = BackgroundChild::GetForCurrentThread()) { - nsresult rv = BackgroundActorCreated(bgActor); - if (NS_WARN_IF(NS_FAILED(rv))) { - IDB_REPORT_INTERNAL_ERR(); - aRv.Throw(NS_ERROR_DOM_INDEXEDDB_UNKNOWN_ERR); - return nullptr; - } - MOZ_ASSERT(mBackgroundActor); - } else if (mPendingRequests.IsEmpty()) { - // We need to start the sequence to create a background actor for this - // thread. - nsRefPtr cb = - new BackgroundCreateCallback(this); - if (NS_WARN_IF(!BackgroundChild::GetOrCreateForCurrentThread(cb))) { - IDB_REPORT_INTERNAL_ERR(); - aRv.Throw(NS_ERROR_DOM_INDEXEDDB_UNKNOWN_ERR); - return nullptr; + if (!mBackgroundActor && mPendingRequests.IsEmpty()) { + // We need to start the sequence to create a background actor for this + // thread. + BackgroundChildImpl::ThreadLocal* threadLocal = + BackgroundChildImpl::GetThreadLocalForCurrentThread(); + + nsAutoPtr newIDBThreadLocal; + ThreadLocal* idbThreadLocal; + + if (threadLocal && threadLocal->mIndexedDBThreadLocal) { + idbThreadLocal = threadLocal->mIndexedDBThreadLocal; + } else { + nsCOMPtr uuidGen = + do_GetService("@mozilla.org/uuid-generator;1"); + MOZ_ASSERT(uuidGen); + + nsID id; + MOZ_ALWAYS_TRUE(NS_SUCCEEDED(uuidGen->GenerateUUIDInPlace(&id))); + + newIDBThreadLocal = idbThreadLocal = new ThreadLocal(id); + } + + nsRefPtr cb = + new BackgroundCreateCallback(this, idbThreadLocal->GetLoggingInfo()); + if (NS_WARN_IF(!BackgroundChild::GetOrCreateForCurrentThread(cb))) { + IDB_REPORT_INTERNAL_ERR(); + aRv.Throw(NS_ERROR_DOM_INDEXEDDB_UNKNOWN_ERR); + return nullptr; + } + + if (newIDBThreadLocal) { + if (!threadLocal) { + threadLocal = BackgroundChildImpl::GetThreadLocalForCurrentThread(); } + MOZ_ASSERT(threadLocal); + MOZ_ASSERT(!threadLocal->mIndexedDBThreadLocal); + + threadLocal->mIndexedDBThreadLocal = newIDBThreadLocal.forget(); } } @@ -550,6 +583,23 @@ IDBFactory::OpenInternal(nsIPrincipal* aPrincipal, MOZ_ASSERT(request); + if (aDeleting) { + IDB_LOG_MARK("IndexedDB %s: Child Request[%llu]: " + "indexedDB.deleteDatabase(\"%s\")", + "IndexedDB %s: C R[%llu]: IDBFactory.deleteDatabase()", + IDB_LOG_ID_STRING(), + request->LoggingSerialNumber(), + NS_ConvertUTF16toUTF8(aName).get()); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Request[%llu]: " + "indexedDB.open(\"%s\", %s)", + "IndexedDB %s: C R[%llu]: IDBFactory.open()", + IDB_LOG_ID_STRING(), + request->LoggingSerialNumber(), + NS_ConvertUTF16toUTF8(aName).get(), + IDB_LOG_STRINGIFY(aVersion)); + } + // If we already have a background actor then we can start this request now. if (mBackgroundActor) { nsresult rv = InitiateRequest(request, params); @@ -562,27 +612,12 @@ IDBFactory::OpenInternal(nsIPrincipal* aPrincipal, mPendingRequests.AppendElement(new PendingRequestInfo(request, params)); } -#ifdef IDB_PROFILER_USE_MARKS - { - NS_ConvertUTF16toUTF8 profilerName(aName); - if (aDeleting) { - IDB_PROFILER_MARK("IndexedDB Request %llu: deleteDatabase(\"%s\")", - "MT IDBFactory.deleteDatabase()", - request->GetSerialNumber(), profilerName.get()); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: open(\"%s\", %lld)", - "MT IDBFactory.open()", - request->GetSerialNumber(), profilerName.get(), - aVersion); - } - } -#endif - return request.forget(); } nsresult -IDBFactory::BackgroundActorCreated(PBackgroundChild* aBackgroundActor) +IDBFactory::BackgroundActorCreated(PBackgroundChild* aBackgroundActor, + const LoggingInfo& aLoggingInfo) { MOZ_ASSERT(aBackgroundActor); MOZ_ASSERT(!mBackgroundActor); @@ -595,7 +630,8 @@ IDBFactory::BackgroundActorCreated(PBackgroundChild* aBackgroundActor) mBackgroundActor = static_cast( - aBackgroundActor->SendPBackgroundIDBFactoryConstructor(actor)); + aBackgroundActor->SendPBackgroundIDBFactoryConstructor(actor, + aLoggingInfo)); } if (NS_WARN_IF(!mBackgroundActor)) { @@ -735,7 +771,7 @@ IDBFactory::BackgroundCreateCallback::ActorCreated(PBackgroundChild* aActor) nsRefPtr factory; mFactory.swap(factory); - factory->BackgroundActorCreated(aActor); + factory->BackgroundActorCreated(aActor, mLoggingInfo); } void diff --git a/dom/indexedDB/IDBFactory.h b/dom/indexedDB/IDBFactory.h index b88d055195bd..d4f15ffe3f10 100644 --- a/dom/indexedDB/IDBFactory.h +++ b/dom/indexedDB/IDBFactory.h @@ -42,6 +42,7 @@ namespace indexedDB { class BackgroundFactoryChild; class FactoryRequestParams; class IDBOpenDBRequest; +class LoggingInfo; class IDBFactory MOZ_FINAL : public nsISupports @@ -112,6 +113,9 @@ public: mBackgroundActor = nullptr; } + void + IncrementParentLoggingRequestSerialNumber(); + nsPIDOMWindow* GetParentObject() const { @@ -208,7 +212,8 @@ private: ErrorResult& aRv); nsresult - BackgroundActorCreated(PBackgroundChild* aBackgroundActor); + BackgroundActorCreated(PBackgroundChild* aBackgroundActor, + const LoggingInfo& aLoggingInfo); void BackgroundActorFailed(); diff --git a/dom/indexedDB/IDBIndex.cpp b/dom/indexedDB/IDBIndex.cpp index a8a3e74bc677..ff4af101379f 100644 --- a/dom/indexedDB/IDBIndex.cpp +++ b/dom/indexedDB/IDBIndex.cpp @@ -264,33 +264,38 @@ IDBIndex::GetInternal(bool aKeyOnly, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (aKeyOnly) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "getKey(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBIndex.getKey()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "get(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBIndex.get()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + } + BackgroundRequestChild* actor = new BackgroundRequestChild(request); transaction->StartRequest(actor, params); - if (aKeyOnly) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "getKey(%s)", - "IDBRequest[%llu] MT IDBIndex.getKey()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(transaction->Database()), - IDB_PROFILER_STRING(transaction), - IDB_PROFILER_STRING(mObjectStore), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKey)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "get(%s)", - "IDBRequest[%llu] MT IDBIndex.get()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(transaction->Database()), - IDB_PROFILER_STRING(transaction), - IDB_PROFILER_STRING(mObjectStore), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKey)); - } return request.forget(); } @@ -340,36 +345,40 @@ IDBIndex::GetAllInternal(bool aKeysOnly, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (aKeysOnly) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "getAllKeys(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBIndex.getAllKeys()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(aLimit)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "getAll(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBIndex.getAll()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(aLimit)); + } + BackgroundRequestChild* actor = new BackgroundRequestChild(request); transaction->StartRequest(actor, params); - if (aKeysOnly) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "getAllKeys(%s, %lu)", - "IDBRequest[%llu] MT IDBIndex.getAllKeys()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(transaction->Database()), - IDB_PROFILER_STRING(transaction), - IDB_PROFILER_STRING(mObjectStore), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKeyRange), - aLimit); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "getAll(%s, %lu)", - "IDBRequest[%llu] MT IDBIndex.getAll()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(transaction->Database()), - IDB_PROFILER_STRING(transaction), - IDB_PROFILER_STRING(mObjectStore), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKeyRange), - aLimit); - } - return request.forget(); } @@ -432,6 +441,37 @@ IDBIndex::OpenCursorInternal(bool aKeysOnly, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (aKeysOnly) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "openKeyCursor(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBIndex.openKeyCursor()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(direction)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "openCursor(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: " + "IDBObjectStore.openKeyCursor()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(direction)); + } + BackgroundCursorChild* actor = new BackgroundCursorChild(request, this, direction); @@ -474,21 +514,23 @@ IDBIndex::Count(JSContext* aCx, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).index(%s)." + "count(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.count()", + IDB_LOG_ID_STRING(), + transaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(transaction->Database()), + IDB_LOG_STRINGIFY(transaction), + IDB_LOG_STRINGIFY(mObjectStore), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + BackgroundRequestChild* actor = new BackgroundRequestChild(request); transaction->StartRequest(actor, params); - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).index(%s)." - "count(%s)", - "IDBRequest[%llu] MT IDBObjectStore.count()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(transaction->Database()), - IDB_PROFILER_STRING(transaction), - IDB_PROFILER_STRING(mObjectStore), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKey)); - return request.forget(); } diff --git a/dom/indexedDB/IDBObjectStore.cpp b/dom/indexedDB/IDBObjectStore.cpp index a45b3aa4b140..93669d885918 100644 --- a/dom/indexedDB/IDBObjectStore.cpp +++ b/dom/indexedDB/IDBObjectStore.cpp @@ -1143,10 +1143,12 @@ IDBObjectStore::AddOrPut(JSContext* aCx, JS::Handle aValue, JS::Handle aKey, bool aOverwrite, + bool aFromCursor, ErrorResult& aRv) { AssertIsOnOwningThread(); MOZ_ASSERT(aCx); + MOZ_ASSERT_IF(aFromCursor, aOverwrite); if (!mTransaction->IsOpen()) { aRv.Throw(NS_ERROR_DOM_INDEXEDDB_TRANSACTION_INACTIVE_ERR); @@ -1249,6 +1251,32 @@ IDBObjectStore::AddOrPut(JSContext* aCx, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (!aFromCursor) { + if (aOverwrite) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).put(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.put()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(key)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).add(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.add()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(key)); + } + } + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); @@ -1261,28 +1289,6 @@ IDBObjectStore::AddOrPut(JSContext* aCx, MOZ_ASSERT(fileInfos.IsEmpty()); } -#ifdef IDB_PROFILER_USE_MARKS - if (aOverwrite) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).%s(%s)", - "IDBRequest[%llu] MT IDBObjectStore.put()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), - key.IsUnset() ? "" : IDB_PROFILER_STRING(key)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).add(%s)", - "IDBRequest[%llu] MT IDBObjectStore.add()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), - key.IsUnset() ? "" : IDB_PROFILER_STRING(key)); - } -#endif - return request.forget(); } @@ -1329,36 +1335,38 @@ IDBObjectStore::GetAllInternal(bool aKeysOnly, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (aKeysOnly) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "getAllKeys(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.getAllKeys()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(aLimit)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "getAll(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.getAll()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(aLimit)); + } + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); -#ifdef IDB_PROFILER_USE_MARKS - if (aKeysOnly) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "getAllKeys(%s, %lu)", - "IDBRequest[%llu] MT IDBObjectStore.getAllKeys()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKeyRange), - aLimit); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "getAll(%s, %lu)", - "IDBRequest[%llu] MT IDBObjectStore.getAll()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), - IDB_PROFILER_STRING(aKeyRange), - aLimit); - } -#endif - return request.forget(); } @@ -1383,18 +1391,20 @@ IDBObjectStore::Clear(ErrorResult& aRv) nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).clear()", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.clear()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this)); + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).clear()", - "IDBRequest[%llu] MT IDBObjectStore.clear()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this)); - return request.forget(); } @@ -1579,25 +1589,29 @@ IDBObjectStore::Get(JSContext* aCx, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).get(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.get()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).get(%s)", - "IDBRequest[%llu] MT IDBObjectStore.get()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(aKeyRange)); - return request.forget(); } already_AddRefed -IDBObjectStore::Delete(JSContext* aCx, - JS::Handle aKey, - ErrorResult& aRv) +IDBObjectStore::DeleteInternal(JSContext* aCx, + JS::Handle aKey, + bool aFromCursor, + ErrorResult& aRv) { AssertIsOnOwningThread(); @@ -1630,18 +1644,23 @@ IDBObjectStore::Delete(JSContext* aCx, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (!aFromCursor) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).delete(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.delete()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + } + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).delete(%s)", - "IDBRequest[%llu] MT IDBObjectStore.delete()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(aKeyRange)); - return request.forget(); } @@ -1751,13 +1770,20 @@ IDBObjectStore::CreateIndexInternal( mIndexes.AppendElement(index); - IDB_PROFILER_MARK("IndexedDB Pseudo-request: " - "database(%s).transaction(%s).objectStore(%s)." - "createIndex(%s)", - "MT IDBObjectStore.createIndex()", - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(index)); + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).createIndex(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.createIndex()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(index)); return index.forget(); } @@ -1816,16 +1842,23 @@ IDBObjectStore::DeleteIndex(const nsAString& aName, ErrorResult& aRv) return; } - transaction->DeleteIndex(this, foundId); + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); - IDB_PROFILER_MARK("IndexedDB Pseudo-request: " - "database(%s).transaction(%s).objectStore(%s)." - "deleteIndex(\"%s\")", - "MT IDBObjectStore.deleteIndex()", - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), - NS_ConvertUTF16toUTF8(aName).get()); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "deleteIndex(\"%s\")", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.deleteIndex()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + requestSerialNumber, + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + NS_ConvertUTF16toUTF8(aName).get()); + + transaction->DeleteIndex(this, foundId); } already_AddRefed @@ -1858,18 +1891,21 @@ IDBObjectStore::Count(JSContext* aCx, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s).count(%s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.count()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange)); + BackgroundRequestChild* actor = new BackgroundRequestChild(request); mTransaction->StartRequest(actor, params); - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s).count(%s)", - "IDBRequest[%llu] MT IDBObjectStore.count()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(aKeyRange)); - return request.forget(); } @@ -1928,34 +1964,40 @@ IDBObjectStore::OpenCursorInternal(bool aKeysOnly, nsRefPtr request = GenerateRequest(this); MOZ_ASSERT(request); + if (aKeysOnly) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "openKeyCursor(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: " + "IDBObjectStore.openKeyCursor()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(direction)); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "database(%s).transaction(%s).objectStore(%s)." + "openCursor(%s, %s)", + "IndexedDB %s: C T[%lld] R[%llu]: IDBObjectStore.openCursor()", + IDB_LOG_ID_STRING(), + mTransaction->LoggingSerialNumber(), + request->LoggingSerialNumber(), + IDB_LOG_STRINGIFY(mTransaction->Database()), + IDB_LOG_STRINGIFY(mTransaction), + IDB_LOG_STRINGIFY(this), + IDB_LOG_STRINGIFY(keyRange), + IDB_LOG_STRINGIFY(direction)); + } + BackgroundCursorChild* actor = new BackgroundCursorChild(request, this, direction); mTransaction->OpenCursor(actor, params); -#ifdef IDB_PROFILER_USE_MARKS - if (aKeysOnly) { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "openKeyCursor(%s, %s)", - "IDBRequest[%llu] MT IDBObjectStore.openKeyCursor()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(aKeyRange), - IDB_PROFILER_STRING(direction)); - } else { - IDB_PROFILER_MARK("IndexedDB Request %llu: " - "database(%s).transaction(%s).objectStore(%s)." - "openCursor(%s, %s)", - "IDBRequest[%llu] MT IDBObjectStore.openKeyCursor()", - request->GetSerialNumber(), - IDB_PROFILER_STRING(Transaction()->Database()), - IDB_PROFILER_STRING(Transaction()), - IDB_PROFILER_STRING(this), IDB_PROFILER_STRING(aKeyRange), - IDB_PROFILER_STRING(direction)); - } -#endif return request.forget(); } diff --git a/dom/indexedDB/IDBObjectStore.h b/dom/indexedDB/IDBObjectStore.h index 1ce9c869bac6..73e14c7b5617 100644 --- a/dom/indexedDB/IDBObjectStore.h +++ b/dom/indexedDB/IDBObjectStore.h @@ -33,6 +33,7 @@ template class Sequence; namespace indexedDB { class FileManager; +class IDBCursor; class IDBKeyRange; class IDBRequest; class IDBTransaction; @@ -47,6 +48,9 @@ class IDBObjectStore MOZ_FINAL : public nsISupports , public nsWrapperCache { + // For AddOrPut() and DeleteInternal(). + friend class IDBCursor; + static const JSClass sDummyPropJSClass; nsRefPtr mTransaction; @@ -160,7 +164,7 @@ public: { AssertIsOnOwningThread(); - return AddOrPut(aCx, aValue, aKey, false, aRv); + return AddOrPut(aCx, aValue, aKey, false, /* aFromCursor */ false, aRv); } already_AddRefed @@ -171,11 +175,18 @@ public: { AssertIsOnOwningThread(); - return AddOrPut(aCx, aValue, aKey, true, aRv); + return AddOrPut(aCx, aValue, aKey, true, /* aFromCursor */ false, aRv); } already_AddRefed - Delete(JSContext* aCx, JS::Handle aKey, ErrorResult& aRv); + Delete(JSContext* aCx, + JS::Handle aKey, + ErrorResult& aRv) + { + AssertIsOnOwningThread(); + + return DeleteInternal(aCx, aKey, /* aFromCursor */ false, aRv); + } already_AddRefed Get(JSContext* aCx, JS::Handle aKey, ErrorResult& aRv); @@ -288,8 +299,15 @@ private: JS::Handle aValue, JS::Handle aKey, bool aOverwrite, + bool aFromCursor, ErrorResult& aRv); + already_AddRefed + DeleteInternal(JSContext* aCx, + JS::Handle aKey, + bool aFromCursor, + ErrorResult& aRv); + already_AddRefed GetAllInternal(bool aKeysOnly, JSContext* aCx, diff --git a/dom/indexedDB/IDBRequest.cpp b/dom/indexedDB/IDBRequest.cpp index 388e8046131a..7ddd08d4b992 100644 --- a/dom/indexedDB/IDBRequest.cpp +++ b/dom/indexedDB/IDBRequest.cpp @@ -29,6 +29,9 @@ #include "nsString.h" #include "ReportInternalError.h" +// Include this last to avoid path problems on Windows. +#include "ActorsChild.h" + namespace mozilla { namespace dom { namespace indexedDB { @@ -75,19 +78,10 @@ IDBRequest::InitMembers() AssertIsOnOwningThread(); mResultVal.setUndefined(); + mLoggingSerialNumber = NextSerialNumber(); mErrorCode = NS_OK; mLineNo = 0; mHaveResultOrErrorCode = false; - -#ifdef MOZ_ENABLE_PROFILER_SPS - { - BackgroundChildImpl::ThreadLocal* threadLocal = - BackgroundChildImpl::GetThreadLocalForCurrentThread(); - MOZ_ASSERT(threadLocal); - - mSerialNumber = threadLocal->mNextRequestSerialNumber++; - } -#endif } // static @@ -140,6 +134,28 @@ IDBRequest::Create(IDBIndex* aSourceAsIndex, } // static +uint64_t +IDBRequest::NextSerialNumber() +{ + BackgroundChildImpl::ThreadLocal* threadLocal = + BackgroundChildImpl::GetThreadLocalForCurrentThread(); + MOZ_ASSERT(threadLocal); + + ThreadLocal* idbThreadLocal = threadLocal->mIndexedDBThreadLocal; + MOZ_ASSERT(idbThreadLocal); + + return idbThreadLocal->NextRequestSN(); +} + +void +IDBRequest::SetLoggingSerialNumber(uint64_t aLoggingSerialNumber) +{ + AssertIsOnOwningThread(); + MOZ_ASSERT(aLoggingSerialNumber > mLoggingSerialNumber); + + mLoggingSerialNumber = aLoggingSerialNumber; +} + void IDBRequest::CaptureCaller(nsAString& aFilename, uint32_t* aLineNo) { diff --git a/dom/indexedDB/IDBRequest.h b/dom/indexedDB/IDBRequest.h index 170dc0e25624..af3e1e929fdc 100644 --- a/dom/indexedDB/IDBRequest.h +++ b/dom/indexedDB/IDBRequest.h @@ -58,9 +58,7 @@ protected: nsRefPtr mError; nsString mFilename; -#ifdef MOZ_ENABLE_PROFILER_SPS - uint64_t mSerialNumber; -#endif + uint64_t mLoggingSerialNumber; nsresult mErrorCode; uint32_t mLineNo; bool mHaveResultOrErrorCode; @@ -84,6 +82,9 @@ public: static void CaptureCaller(nsAString& aFilename, uint32_t* aLineNo); + static uint64_t + NextSerialNumber(); + // nsIDOMEventTarget virtual nsresult PreHandleEvent(EventChainPreVisitor& aVisitor) MOZ_OVERRIDE; @@ -125,13 +126,16 @@ public: return !mHaveResultOrErrorCode; } -#ifdef MOZ_ENABLE_PROFILER_SPS uint64_t - GetSerialNumber() const + LoggingSerialNumber() const { - return mSerialNumber; + AssertIsOnOwningThread(); + + return mLoggingSerialNumber; } -#endif + + void + SetLoggingSerialNumber(uint64_t aLoggingSerialNumber); nsPIDOMWindow* GetParentObject() const diff --git a/dom/indexedDB/IDBTransaction.cpp b/dom/indexedDB/IDBTransaction.cpp index a914dc1b2f86..07c99596bbdb 100644 --- a/dom/indexedDB/IDBTransaction.cpp +++ b/dom/indexedDB/IDBTransaction.cpp @@ -32,6 +32,8 @@ namespace mozilla { namespace dom { namespace indexedDB { +using namespace mozilla::ipc; + namespace { NS_DEFINE_CID(kAppShellCID, NS_APPSHELL_CID); @@ -44,6 +46,7 @@ IDBTransaction::IDBTransaction(IDBDatabase* aDatabase, : IDBWrapperCache(aDatabase) , mDatabase(aDatabase) , mObjectStoreNames(aObjectStoreNames) + , mLoggingSerialNumber(0) , mNextObjectStoreId(0) , mNextIndexId(0) , mAbortCode(NS_OK) @@ -63,16 +66,15 @@ IDBTransaction::IDBTransaction(IDBDatabase* aDatabase, mBackgroundActor.mNormalBackgroundActor = nullptr; -#ifdef MOZ_ENABLE_PROFILER_SPS - { - using namespace mozilla::ipc; - BackgroundChildImpl::ThreadLocal* threadLocal = - BackgroundChildImpl::GetThreadLocalForCurrentThread(); - MOZ_ASSERT(threadLocal); + BackgroundChildImpl::ThreadLocal* threadLocal = + BackgroundChildImpl::GetThreadLocalForCurrentThread(); + MOZ_ASSERT(threadLocal); - mSerialNumber = threadLocal->mNextTransactionSerialNumber++; - } -#endif + ThreadLocal* idbThreadLocal = threadLocal->mIndexedDBThreadLocal; + MOZ_ASSERT(idbThreadLocal); + + const_cast(mLoggingSerialNumber) = + idbThreadLocal->NextTransactionSN(aMode); #ifdef DEBUG if (!aObjectStoreNames.IsEmpty()) { @@ -111,13 +113,15 @@ IDBTransaction::~IDBTransaction() mDatabase->UnregisterTransaction(this); if (mMode == VERSION_CHANGE) { - if (mBackgroundActor.mVersionChangeBackgroundActor) { - mBackgroundActor.mVersionChangeBackgroundActor->SendDeleteMeInternal(); + if (auto* actor = mBackgroundActor.mVersionChangeBackgroundActor) { + actor->SendDeleteMeInternal(); + MOZ_ASSERT(!mBackgroundActor.mVersionChangeBackgroundActor, "SendDeleteMeInternal should have cleared!"); } - } else if (mBackgroundActor.mNormalBackgroundActor) { - mBackgroundActor.mNormalBackgroundActor->SendDeleteMeInternal(); + } else if (auto* actor = mBackgroundActor.mNormalBackgroundActor) { + actor->SendDeleteMeInternal(); + MOZ_ASSERT(!mBackgroundActor.mNormalBackgroundActor, "SendDeleteMeInternal should have cleared!"); } @@ -212,7 +216,10 @@ IDBTransaction::GetCurrent() BackgroundChildImpl::GetThreadLocalForCurrentThread(); MOZ_ASSERT(threadLocal); - return threadLocal->mCurrentTransaction; + ThreadLocal* idbThreadLocal = threadLocal->mIndexedDBThreadLocal; + MOZ_ASSERT(idbThreadLocal); + + return idbThreadLocal->GetCurrentTransaction(); } #ifdef DEBUG @@ -339,6 +346,18 @@ IDBTransaction::SendCommit() MOZ_ASSERT(NS_SUCCEEDED(mAbortCode)); MOZ_ASSERT(IsFinished()); MOZ_ASSERT(!mSentCommitOrAbort); + MOZ_ASSERT(!mPendingRequestCount); + + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "All requests complete, committing transaction", + "IndexedDB %s: C T[%lld] R[%llu]: IDBTransaction commit", + IDB_LOG_ID_STRING(), + LoggingSerialNumber(), + requestSerialNumber); if (mMode == VERSION_CHANGE) { MOZ_ASSERT(mBackgroundActor.mVersionChangeBackgroundActor); @@ -361,6 +380,18 @@ IDBTransaction::SendAbort(nsresult aResultCode) MOZ_ASSERT(IsFinished()); MOZ_ASSERT(!mSentCommitOrAbort); + // Don't do this in the macro because we always need to increment the serial + // number to keep in sync with the parent. + const uint64_t requestSerialNumber = IDBRequest::NextSerialNumber(); + + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld] Request[%llu]: " + "Aborting transaction with result 0x%x", + "IndexedDB %s: C T[%lld] R[%llu]: IDBTransaction abort (0x%x)", + IDB_LOG_ID_STRING(), + LoggingSerialNumber(), + requestSerialNumber, + aResultCode); + if (mMode == VERSION_CHANGE) { MOZ_ASSERT(mBackgroundActor.mVersionChangeBackgroundActor); mBackgroundActor.mVersionChangeBackgroundActor->SendAbort(aResultCode); @@ -517,11 +548,14 @@ IDBTransaction::AbortInternal(nsresult aAbortCode, const bool isInvalidated = mDatabase->IsInvalidated(); bool needToSendAbort = mReadyState == INITIAL && !isInvalidated; -#ifdef DEBUG if (isInvalidated) { +#ifdef DEBUG mSentCommitOrAbort = true; - } #endif + // Increment the serial number counter here to account for the aborted + // transaction and keep the parent in sync. + IDBRequest::NextSerialNumber(); + } mAbortCode = aAbortCode; mReadyState = DONE; @@ -639,10 +673,6 @@ IDBTransaction::FireCompleteOrAbortEvents(nsresult aResult) AssertIsOnOwningThread(); MOZ_ASSERT(!mFiredCompleteOrAbort); - IDB_PROFILER_MARK("IndexedDB Transaction %llu: Complete (rv = %lu)", - "IDBTransaction[%llu] MT Complete", - mTransaction->GetSerialNumber(), mAbortCode); - mReadyState = DONE; #ifdef DEBUG @@ -670,6 +700,21 @@ IDBTransaction::FireCompleteOrAbortEvents(nsresult aResult) return; } + if (NS_SUCCEEDED(mAbortCode)) { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld]: " + "Firing 'complete' event", + "IndexedDB %s: C T[%lld]: IDBTransaction 'complete' event", + IDB_LOG_ID_STRING(), + mLoggingSerialNumber); + } else { + IDB_LOG_MARK("IndexedDB %s: Child Transaction[%lld]: " + "Firing 'abort' event with error 0x%x", + "IndexedDB %s: C T[%lld]: IDBTransaction 'abort' event (0x%x)", + IDB_LOG_ID_STRING(), + mLoggingSerialNumber, + mAbortCode); + } + bool dummy; if (NS_FAILED(DispatchEvent(event, &dummy))) { NS_WARNING("DispatchEvent failed!"); diff --git a/dom/indexedDB/IDBTransaction.h b/dom/indexedDB/IDBTransaction.h index 73771c4f37c3..07c2b9acc82e 100644 --- a/dom/indexedDB/IDBTransaction.h +++ b/dom/indexedDB/IDBTransaction.h @@ -83,15 +83,12 @@ private: BackgroundVersionChangeTransactionChild* mVersionChangeBackgroundActor; } mBackgroundActor; + const int64_t mLoggingSerialNumber; // Only used for VERSION_CHANGE transactions. int64_t mNextObjectStoreId; int64_t mNextIndexId; -#ifdef MOZ_ENABLE_PROFILER_SPS - uint64_t mSerialNumber; -#endif - nsresult mAbortCode; uint32_t mPendingRequestCount; @@ -245,14 +242,13 @@ public: void Abort(nsresult aAbortCode); -#ifdef MOZ_ENABLE_PROFILER_SPS - uint32_t - GetSerialNumber() const + int64_t + LoggingSerialNumber() const { AssertIsOnOwningThread(); - return mSerialNumber; + + return mLoggingSerialNumber; } -#endif nsPIDOMWindow* GetParentObject() const; diff --git a/dom/indexedDB/IndexedDatabaseManager.cpp b/dom/indexedDB/IndexedDatabaseManager.cpp index 7d41156cd858..3b8671349162 100644 --- a/dom/indexedDB/IndexedDatabaseManager.cpp +++ b/dom/indexedDB/IndexedDatabaseManager.cpp @@ -32,11 +32,13 @@ #include "mozilla/storage.h" #include "nsContentUtils.h" #include "nsThreadUtils.h" +#include "prlog.h" #include "IDBEvents.h" #include "IDBFactory.h" #include "IDBKeyRange.h" #include "IDBRequest.h" +#include "ProfilerHelpers.h" // Bindings for ResolveConstructors #include "mozilla/dom/IDBCursorBinding.h" @@ -111,7 +113,22 @@ private: namespace { -const char kTestingPref[] = "dom.indexedDB.testing"; +#define IDB_PREF_BRANCH_ROOT "dom.indexedDB." + +const char kTestingPref[] = IDB_PREF_BRANCH_ROOT "testing"; + +#define IDB_PREF_LOGGING_BRANCH_ROOT IDB_PREF_BRANCH_ROOT "logging." + +const char kPrefLoggingEnabled[] = IDB_PREF_LOGGING_BRANCH_ROOT "enabled"; +const char kPrefLoggingDetails[] = IDB_PREF_LOGGING_BRANCH_ROOT "details"; + +#if defined(DEBUG) || defined(MOZ_ENABLE_PROFILER_SPS) +const char kPrefLoggingProfiler[] = + IDB_PREF_LOGGING_BRANCH_ROOT "profiler-marks"; +#endif + +#undef IDB_PREF_LOGGING_BRANCH_ROOT +#undef IDB_PREF_BRANCH_ROOT mozilla::StaticRefPtr gDBManager; @@ -205,6 +222,13 @@ IndexedDatabaseManager::~IndexedDatabaseManager() bool IndexedDatabaseManager::sIsMainProcess = false; bool IndexedDatabaseManager::sFullSynchronousMode = false; + +PRLogModuleInfo* IndexedDatabaseManager::sLoggingModule; + +Atomic + IndexedDatabaseManager::sLoggingMode( + IndexedDatabaseManager::Logging_Disabled); + mozilla::Atomic IndexedDatabaseManager::sLowDiskSpaceMode(false); // static @@ -221,6 +245,10 @@ IndexedDatabaseManager::GetOrCreate() if (!gDBManager) { sIsMainProcess = XRE_GetProcessType() == GeckoProcessType_Default; + if (!sLoggingModule) { + sLoggingModule = PR_NewLogModule("IndexedDB"); + } + if (sIsMainProcess && Preferences::GetBool("disk_space_watcher.enabled", false)) { // See if we're starting up in low disk space conditions. nsCOMPtr watcher = @@ -300,6 +328,15 @@ IndexedDatabaseManager::Init() // hit. sFullSynchronousMode = Preferences::GetBool("dom.indexedDB.fullSynchronous"); + Preferences::RegisterCallback(LoggingModePrefChangedCallback, + kPrefLoggingDetails); +#ifdef MOZ_ENABLE_PROFILER_SPS + Preferences::RegisterCallback(LoggingModePrefChangedCallback, + kPrefLoggingProfiler); +#endif + Preferences::RegisterCallbackAndCall(LoggingModePrefChangedCallback, + kPrefLoggingEnabled); + return NS_OK; } @@ -314,6 +351,15 @@ IndexedDatabaseManager::Destroy() Preferences::UnregisterCallback(TestingPrefChangedCallback, kTestingPref); + Preferences::UnregisterCallback(LoggingModePrefChangedCallback, + kPrefLoggingDetails); +#ifdef MOZ_ENABLE_PROFILER_SPS + Preferences::UnregisterCallback(LoggingModePrefChangedCallback, + kPrefLoggingProfiler); +#endif + Preferences::UnregisterCallback(LoggingModePrefChangedCallback, + kPrefLoggingEnabled); + delete this; } @@ -491,7 +537,30 @@ IndexedDatabaseManager::InLowDiskSpaceMode() "initialized!"); return sLowDiskSpaceMode; } -#endif + +// static +IndexedDatabaseManager::LoggingMode +IndexedDatabaseManager::GetLoggingMode() +{ + MOZ_ASSERT(gDBManager, + "GetLoggingMode called before IndexedDatabaseManager has been " + "initialized!"); + + return sLoggingMode; +} + +// static +PRLogModuleInfo* +IndexedDatabaseManager::GetLoggingModule() +{ + MOZ_ASSERT(gDBManager, + "GetLoggingModule called before IndexedDatabaseManager has been " + "initialized!"); + + return sLoggingModule; +} + +#endif // DEBUG // static bool @@ -687,6 +756,44 @@ IndexedDatabaseManager::BlockAndGetFileReferences( return NS_OK; } +// static +void +IndexedDatabaseManager::LoggingModePrefChangedCallback( + const char* /* aPrefName */, + void* /* aClosure */) +{ + MOZ_ASSERT(NS_IsMainThread()); + + if (!Preferences::GetBool(kPrefLoggingEnabled)) { + sLoggingMode = Logging_Disabled; + return; + } + + bool useProfiler = +#if defined(DEBUG) || defined(MOZ_ENABLE_PROFILER_SPS) + Preferences::GetBool(kPrefLoggingProfiler); +#if !defined(MOZ_ENABLE_PROFILER_SPS) + if (useProfiler) { + NS_WARNING("IndexedDB cannot create profiler marks because this build does " + "not have profiler extensions enabled!"); + useProfiler = false; + } +#endif +#else + false; +#endif + + const bool logDetails = Preferences::GetBool(kPrefLoggingDetails); + + if (useProfiler) { + sLoggingMode = logDetails ? + Logging_DetailedProfilerMarks : + Logging_ConciseProfilerMarks; + } else { + sLoggingMode = logDetails ? Logging_Detailed : Logging_Concise; + } +} + NS_IMPL_ADDREF(IndexedDatabaseManager) NS_IMPL_RELEASE_WITH_DESTROY(IndexedDatabaseManager, Destroy()) NS_IMPL_QUERY_INTERFACE(IndexedDatabaseManager, nsIObserver) diff --git a/dom/indexedDB/IndexedDatabaseManager.h b/dom/indexedDB/IndexedDatabaseManager.h index 71bea9f7f786..6621b74a1b66 100644 --- a/dom/indexedDB/IndexedDatabaseManager.h +++ b/dom/indexedDB/IndexedDatabaseManager.h @@ -17,6 +17,7 @@ #include "nsHashKeys.h" class nsPIDOMWindow; +struct PRLogModuleInfo; namespace mozilla { @@ -36,6 +37,15 @@ class IndexedDatabaseManager MOZ_FINAL : public nsIObserver typedef mozilla::dom::quota::PersistenceType PersistenceType; public: + enum LoggingMode + { + Logging_Disabled = 0, + Logging_Concise, + Logging_Detailed, + Logging_ConciseProfilerMarks, + Logging_DetailedProfilerMarks + }; + NS_DECL_ISUPPORTS NS_DECL_NSIOBSERVER @@ -76,6 +86,26 @@ public: static bool FullSynchronous(); + static LoggingMode + GetLoggingMode() +#ifdef DEBUG + ; +#else + { + return sLoggingMode; + } +#endif + + static PRLogModuleInfo* + GetLoggingModule() +#ifdef DEBUG + ; +#else + { + return sLoggingModule; + } +#endif + already_AddRefed GetFileManager(PersistenceType aPersistenceType, const nsACString& aOrigin, @@ -143,6 +173,9 @@ private: void Destroy(); + static void + LoggingModePrefChangedCallback(const char* aPrefName, void* aClosure); + // Maintains a list of all file managers per origin. This list isn't // protected by any mutex but it is only ever touched on the IO thread. nsClassHashtable mFileManagerInfos; @@ -154,6 +187,8 @@ private: static bool sIsMainProcess; static bool sFullSynchronousMode; + static PRLogModuleInfo* sLoggingModule; + static Atomic sLoggingMode; static mozilla::Atomic sLowDiskSpaceMode; }; diff --git a/dom/indexedDB/PBackgroundIDBFactory.ipdl b/dom/indexedDB/PBackgroundIDBFactory.ipdl index 1fac81f93b16..b44eccf7dc83 100644 --- a/dom/indexedDB/PBackgroundIDBFactory.ipdl +++ b/dom/indexedDB/PBackgroundIDBFactory.ipdl @@ -51,6 +51,8 @@ parent: PBackgroundIDBFactoryRequest(FactoryRequestParams params); + IncrementLoggingRequestSerialNumber(); + child: __delete__(); diff --git a/dom/indexedDB/PBackgroundIDBSharedTypes.ipdlh b/dom/indexedDB/PBackgroundIDBSharedTypes.ipdlh index 5402b256f3de..dc6f88269220 100644 --- a/dom/indexedDB/PBackgroundIDBSharedTypes.ipdlh +++ b/dom/indexedDB/PBackgroundIDBSharedTypes.ipdlh @@ -5,6 +5,8 @@ include protocol PBlob; include protocol PBackgroundIDBDatabaseFile; +include DOMTypes; + include "mozilla/dom/indexedDB/SerializationHelpers.h"; using struct mozilla::void_t @@ -253,6 +255,16 @@ union RequestParams IndexCountParams; }; +struct LoggingInfo +{ + nsID backgroundChildLoggingId; + // This counter is always positive. + int64_t nextTransactionSerialNumber; + // This counter is always negative. + int64_t nextVersionChangeTransactionSerialNumber; + uint64_t nextRequestSerialNumber; +}; + } // namespace indexedDB } // namespace dom } // namespace mozilla diff --git a/dom/indexedDB/ProfilerHelpers.h b/dom/indexedDB/ProfilerHelpers.h index 4afab8469c65..60356d2c7135 100644 --- a/dom/indexedDB/ProfilerHelpers.h +++ b/dom/indexedDB/ProfilerHelpers.h @@ -7,40 +7,76 @@ #ifndef mozilla_dom_indexeddb_profilerhelpers_h__ #define mozilla_dom_indexeddb_profilerhelpers_h__ +// This file is not exported and is only meant to be included in IndexedDB +// source files. + +#include "BackgroundChildImpl.h" #include "GeckoProfiler.h" - -// Uncomment this if you want IndexedDB operations to be marked in the profiler. -//#define IDB_PROFILER_USE_MARKS - -// Uncomment this if you want extended details to appear in profiler marks. -//#define IDB_PROFILER_MARK_DETAILS 0 - -// Sanity check the options above. -#if defined(IDB_PROFILER_USE_MARKS) && !defined(MOZ_ENABLE_PROFILER_SPS) -#error Cannot use IDB_PROFILER_USE_MARKS without MOZ_ENABLE_PROFILER_SPS! -#endif - -#if defined(IDB_PROFILER_MARK_DETAILS) && !defined(IDB_PROFILER_USE_MARKS) -#error Cannot use IDB_PROFILER_MARK_DETAILS without IDB_PROFILER_USE_MARKS! -#endif - -#ifdef IDB_PROFILER_USE_MARKS - -#ifdef IDB_PROFILER_MARK_DETAILS - #include "IDBCursor.h" #include "IDBDatabase.h" #include "IDBIndex.h" #include "IDBKeyRange.h" #include "IDBObjectStore.h" #include "IDBTransaction.h" +#include "IndexedDatabaseManager.h" #include "Key.h" +#include "mozilla/Assertions.h" +#include "mozilla/Attributes.h" +#include "mozilla/dom/BindingDeclarations.h" +#include "nsDebug.h" +#include "nsID.h" +#include "nsIDOMEvent.h" +#include "nsString.h" +#include "prlog.h" + +// Include this last to avoid path problems on Windows. +#include "ActorsChild.h" namespace mozilla { namespace dom { namespace indexedDB { -class ProfilerString : public nsAutoCString +class MOZ_STACK_CLASS LoggingIdString MOZ_FINAL + : public nsAutoCString +{ +public: + LoggingIdString() + { + using mozilla::ipc::BackgroundChildImpl; + + BackgroundChildImpl::ThreadLocal* threadLocal = + BackgroundChildImpl::GetThreadLocalForCurrentThread(); + MOZ_ASSERT(threadLocal); + + ThreadLocal* idbThreadLocal = threadLocal->mIndexedDBThreadLocal; + MOZ_ASSERT(idbThreadLocal); + + Init(idbThreadLocal->Id()); + } + + explicit + LoggingIdString(const nsID& aID) + { + Init(aID); + } + +private: + void + Init(const nsID& aID) + { + static_assert(NSID_LENGTH > 1, "NSID_LENGTH is set incorrectly!"); + MOZ_ASSERT(Capacity() > NSID_LENGTH); + + // NSID_LENGTH counts the null terminator, SetLength() does not. + SetLength(NSID_LENGTH - 1); + + aID.ToProvidedString( + *reinterpret_cast(BeginWriting())); + } +}; + +class MOZ_STACK_CLASS LoggingString MOZ_FINAL + : public nsAutoCString { static const char kQuote = '\"'; static const char kOpenBracket = '['; @@ -50,20 +86,38 @@ class ProfilerString : public nsAutoCString public: explicit - ProfilerString(IDBDatabase* aDatabase) + LoggingString(IDBDatabase* aDatabase) + : nsAutoCString(kQuote) { MOZ_ASSERT(aDatabase); - Append(kQuote); AppendUTF16toUTF8(aDatabase->Name(), *this); Append(kQuote); } explicit - ProfilerString(IDBTransaction* aTransaction) + LoggingString(IDBTransaction* aTransaction) + : nsAutoCString(kOpenBracket) { MOZ_ASSERT(aTransaction); + NS_NAMED_LITERAL_CSTRING(kCommaSpace, ", "); + + const nsTArray& stores = aTransaction->ObjectStoreNamesInternal(); + + for (uint32_t count = stores.Length(), index = 0; index < count; index++) { + Append(kQuote); + AppendUTF16toUTF8(stores[index], *this); + Append(kQuote); + + if (index != count - 1) { + Append(kCommaSpace); + } + } + + Append(kCloseBracket); + Append(kCommaSpace); + switch (aTransaction->GetMode()) { case IDBTransaction::READ_ONLY: AppendLiteral("\"readonly\""); @@ -80,128 +134,198 @@ public: } explicit - ProfilerString(IDBObjectStore* aObjectStore) + LoggingString(IDBObjectStore* aObjectStore) + : nsAutoCString(kQuote) { MOZ_ASSERT(aObjectStore); - Append(kQuote); AppendUTF16toUTF8(aObjectStore->Name(), *this); Append(kQuote); } explicit - ProfilerString(IDBIndex* aIndex) + LoggingString(IDBIndex* aIndex) + : nsAutoCString(kQuote) { MOZ_ASSERT(aIndex); - Append(kQuote); AppendUTF16toUTF8(aIndex->Name(), *this); Append(kQuote); } explicit - ProfilerString(IDBKeyRange* aKeyRange) + LoggingString(IDBKeyRange* aKeyRange) { if (aKeyRange) { if (aKeyRange->IsOnly()) { - Append(ProfilerString(aKeyRange->Lower())); - } - else { - Append(aKeyRange->IsLowerOpen() ? kOpenParen : kOpenBracket); - Append(ProfilerString(aKeyRange->Lower())); + Assign(LoggingString(aKeyRange->Lower())); + } else { + Assign(aKeyRange->LowerOpen() ? kOpenParen : kOpenBracket); + Append(LoggingString(aKeyRange->Lower())); AppendLiteral(", "); - Append(ProfilerString(aKeyRange->Upper())); - Append(aKeyRange->IsUpperOpen() ? kCloseParen : kCloseBracket); + Append(LoggingString(aKeyRange->Upper())); + Append(aKeyRange->UpperOpen() ? kCloseParen : kCloseBracket); } + } else { + AssignLiteral(""); } } explicit - ProfilerString(const Key& aKey) + LoggingString(const Key& aKey) { if (aKey.IsUnset()) { - AssignLiteral("null"); - } - else if (aKey.IsFloat()) { + AssignLiteral(""); + } else if (aKey.IsFloat()) { AppendPrintf("%g", aKey.ToFloat()); - } - else if (aKey.IsDate()) { + } else if (aKey.IsDate()) { AppendPrintf("", aKey.ToDateMsec()); - } - else if (aKey.IsString()) { + } else if (aKey.IsString()) { nsAutoString str; aKey.ToString(str); AppendPrintf("\"%s\"", NS_ConvertUTF16toUTF8(str).get()); - } - else { + } else { MOZ_ASSERT(aKey.IsArray()); - AppendLiteral(""); + AssignLiteral("[...]"); } } explicit - ProfilerString(const IDBCursor::Direction aDirection) + LoggingString(const IDBCursor::Direction aDirection) { switch (aDirection) { case IDBCursor::NEXT: - AppendLiteral("\"next\""); + AssignLiteral("\"next\""); break; case IDBCursor::NEXT_UNIQUE: - AppendLiteral("\"nextunique\""); + AssignLiteral("\"nextunique\""); break; case IDBCursor::PREV: - AppendLiteral("\"prev\""); + AssignLiteral("\"prev\""); break; case IDBCursor::PREV_UNIQUE: - AppendLiteral("\"prevunique\""); + AssignLiteral("\"prevunique\""); break; default: MOZ_CRASH("Unknown direction!"); }; } + + explicit + LoggingString(const Optional& aVersion) + { + if (aVersion.WasPassed()) { + AppendInt(aVersion.Value()); + } else { + AssignLiteral(""); + } + } + + explicit + LoggingString(const Optional& aLimit) + { + if (aLimit.WasPassed()) { + AppendInt(aLimit.Value()); + } else { + AssignLiteral(""); + } + } + + LoggingString(IDBObjectStore* aObjectStore, const Key& aKey) + { + MOZ_ASSERT(aObjectStore); + + if (!aObjectStore->HasValidKeyPath()) { + Append(LoggingString(aKey)); + } + } + + LoggingString(nsIDOMEvent* aEvent, const char16_t* aDefault) + : nsAutoCString(kQuote) + { + MOZ_ASSERT(aDefault); + + nsString eventType; + + if (aEvent) { + MOZ_ALWAYS_TRUE(NS_SUCCEEDED(aEvent->GetType(eventType))); + } else { + eventType = nsDependentString(aDefault); + } + + AppendUTF16toUTF8(eventType, *this); + Append(kQuote); + } }; +inline void +LoggingHelper(bool aUseProfiler, const char* aFmt, ...) +{ + MOZ_ASSERT(IndexedDatabaseManager::GetLoggingMode() != + IndexedDatabaseManager::Logging_Disabled); + MOZ_ASSERT(aFmt); + + PRLogModuleInfo* logModule = IndexedDatabaseManager::GetLoggingModule(); + MOZ_ASSERT(logModule); + + static const PRLogModuleLevel logLevel = PR_LOG_DEBUG; + + if (PR_LOG_TEST(logModule, logLevel) || + (aUseProfiler && profiler_is_active())) { + nsAutoCString message; + + { + va_list args; + va_start(args, aFmt); + + message.AppendPrintf(aFmt, args); + + va_end(args); + } + + PR_LOG(logModule, logLevel, ("%s", message.get())); + + if (aUseProfiler) { + PROFILER_MARKER(message.get()); + } + } +} + } // namespace indexedDB } // namespace dom } // namespace mozilla -#define IDB_PROFILER_MARK(_detailedFmt, _conciseFmt, ...) \ +#define IDB_LOG_MARK(_detailedFmt, _conciseFmt, ...) \ do { \ - nsAutoCString _mark; \ - _mark.AppendPrintf(_detailedFmt, ##__VA_ARGS__); \ - PROFILER_MARKER(_mark.get()); \ - } while (0) - -#define IDB_PROFILER_STRING(_arg) \ - mozilla::dom::indexedDB::ProfilerString((_arg)).get() - -#else // IDB_PROFILER_MARK_DETAILS - -#define IDB_PROFILER_MARK(_detailedFmt, _conciseFmt, ...) \ - do { \ - nsAutoCString _mark; \ - _mark.AppendPrintf(_conciseFmt, ##__VA_ARGS__); \ - PROFILER_MARKER(_mark.get()); \ - } while (0) - -#define IDB_PROFILER_STRING(_arg) "" - -#endif // IDB_PROFILER_MARK_DETAILS - -#define IDB_PROFILER_MARK_IF(_cond, _detailedFmt, _conciseFmt, ...) \ - do { \ - if (_cond) { \ - IDB_PROFILER_MARK(_detailedFmt, _conciseFmt, __VA_ARGS__); \ + using namespace mozilla::dom::indexedDB; \ + \ + const IndexedDatabaseManager::LoggingMode mode = \ + IndexedDatabaseManager::GetLoggingMode(); \ + \ + if (mode != IndexedDatabaseManager::Logging_Disabled) { \ + const char* _fmt; \ + if (mode == IndexedDatabaseManager::Logging_Concise || \ + mode == IndexedDatabaseManager::Logging_ConciseProfilerMarks) { \ + _fmt = _conciseFmt; \ + } else { \ + MOZ_ASSERT( \ + mode == IndexedDatabaseManager::Logging_Detailed || \ + mode == IndexedDatabaseManager::Logging_DetailedProfilerMarks); \ + _fmt = _detailedFmt; \ + } \ + \ + const bool _useProfiler = \ + mode == IndexedDatabaseManager::Logging_ConciseProfilerMarks || \ + mode == IndexedDatabaseManager::Logging_DetailedProfilerMarks; \ + \ + LoggingHelper(_useProfiler, _fmt, ##__VA_ARGS__); \ } \ } while (0) -#else // IDB_PROFILER_USE_MARKS +#define IDB_LOG_ID_STRING(...) \ + mozilla::dom::indexedDB::LoggingIdString(__VA_ARGS__).get() -#define IDB_PROFILER_MARK(...) do { } while(0) -#define IDB_PROFILER_MARK_IF(_cond, ...) do { } while(0) -#define IDB_PROFILER_MARK2(_detailedFmt, _notdetailedFmt, ...) do { } while(0) -#define IDB_PROFILER_STRING(_arg) "" - -#endif // IDB_PROFILER_USE_MARKS +#define IDB_LOG_STRINGIFY(...) \ + mozilla::dom::indexedDB::LoggingString(__VA_ARGS__).get() #endif // mozilla_dom_indexeddb_profilerhelpers_h__ diff --git a/dom/indexedDB/TransactionThreadPool.cpp b/dom/indexedDB/TransactionThreadPool.cpp index f8af510471bf..3cd668b13dad 100644 --- a/dom/indexedDB/TransactionThreadPool.cpp +++ b/dom/indexedDB/TransactionThreadPool.cpp @@ -144,7 +144,9 @@ class TransactionThreadPool::TransactionQueue MOZ_FINAL Monitor mMonitor; nsRefPtr mOwningThreadPool; - uint64_t mTransactionId; + const uint64_t mTransactionId; + const nsID mBackgroundChildLoggingId; + const int64_t mLoggingSerialNumber; const nsCString mDatabaseId; const nsTArray mObjectStoreNames; uint16_t mMode; @@ -155,10 +157,12 @@ class TransactionThreadPool::TransactionQueue MOZ_FINAL public: TransactionQueue(TransactionThreadPool* aThreadPool, - uint64_t aTransactionId, - const nsACString& aDatabaseId, - const nsTArray& aObjectStoreNames, - uint16_t aMode); + uint64_t aTransactionId, + const nsACString& aDatabaseId, + const nsTArray& aObjectStoreNames, + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber); NS_DECL_ISUPPORTS_INHERITED @@ -187,13 +191,21 @@ struct TransactionThreadPool::TransactionInfo MOZ_FINAL uint64_t aTransactionId, const nsACString& aDatabaseId, const nsTArray& aObjectStoreNames, - uint16_t aMode) + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber) : transactionId(aTransactionId), databaseId(aDatabaseId) { MOZ_COUNT_CTOR(TransactionInfo); - queue = new TransactionQueue(aThreadPool, aTransactionId, aDatabaseId, - aObjectStoreNames, aMode); + queue = + new TransactionQueue(aThreadPool, + aTransactionId, + aDatabaseId, + aObjectStoreNames, + aMode, + aBackgroundChildLoggingId, + aLoggingSerialNumber); } ~TransactionInfo() @@ -302,7 +314,6 @@ TransactionThreadPool::Shutdown() } } -// static uint64_t TransactionThreadPool::NextTransactionId() { @@ -548,20 +559,17 @@ TransactionThreadPool::GetQueueForTransaction(uint64_t aTransactionId, } TransactionThreadPool::TransactionQueue& -TransactionThreadPool::GetQueueForTransaction( +TransactionThreadPool::CreateQueueForTransaction( uint64_t aTransactionId, const nsACString& aDatabaseId, const nsTArray& aObjectStoreNames, - uint16_t aMode) + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber) { AssertIsOnOwningThread(); MOZ_ASSERT(aTransactionId <= mNextTransactionId); - - TransactionQueue* existingQueue = - GetQueueForTransaction(aTransactionId, aDatabaseId); - if (existingQueue) { - return *existingQueue; - } + MOZ_ASSERT(!GetQueueForTransaction(aTransactionId, aDatabaseId)); // See if we can run this transaction now. DatabaseTransactionInfo* dbTransactionInfo; @@ -579,11 +587,14 @@ TransactionThreadPool::GetQueueForTransaction( return *info->queue; } - TransactionInfo* transactionInfo = new TransactionInfo(this, - aTransactionId, - aDatabaseId, - aObjectStoreNames, - aMode); + TransactionInfo* transactionInfo = + new TransactionInfo(this, + aTransactionId, + aDatabaseId, + aObjectStoreNames, + aMode, + aBackgroundChildLoggingId, + aLoggingSerialNumber); dbTransactionInfo->transactions.Put(aTransactionId, transactionInfo);; @@ -633,26 +644,27 @@ TransactionThreadPool::GetQueueForTransaction( } void -TransactionThreadPool::Dispatch(uint64_t aTransactionId, - const nsACString& aDatabaseId, - const nsTArray& aObjectStoreNames, - uint16_t aMode, - nsIRunnable* aRunnable, - bool aFinish, - FinishCallback* aFinishCallback) +TransactionThreadPool::Start(uint64_t aTransactionId, + const nsACString& aDatabaseId, + const nsTArray& aObjectStoreNames, + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber, + nsIRunnable* aRunnable) { + AssertIsOnOwningThread(); MOZ_ASSERT(aTransactionId <= mNextTransactionId); + MOZ_ASSERT(aRunnable); MOZ_ASSERT(!mShutdownRequested); - TransactionQueue& queue = GetQueueForTransaction(aTransactionId, - aDatabaseId, - aObjectStoreNames, - aMode); + TransactionQueue& queue = CreateQueueForTransaction(aTransactionId, + aDatabaseId, + aObjectStoreNames, + aMode, + aBackgroundChildLoggingId, + aLoggingSerialNumber); queue.Dispatch(aRunnable); - if (aFinish) { - queue.Finish(aFinishCallback); - } } void @@ -765,14 +777,18 @@ TransactionQueue::TransactionQueue(TransactionThreadPool* aThreadPool, uint64_t aTransactionId, const nsACString& aDatabaseId, const nsTArray& aObjectStoreNames, - uint16_t aMode) -: mMonitor("TransactionQueue::mMonitor"), - mOwningThreadPool(aThreadPool), - mTransactionId(aTransactionId), - mDatabaseId(aDatabaseId), - mObjectStoreNames(aObjectStoreNames), - mMode(aMode), - mShouldFinish(false) + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber) + : mMonitor("TransactionQueue::mMonitor") + , mOwningThreadPool(aThreadPool) + , mTransactionId(aTransactionId) + , mBackgroundChildLoggingId(aBackgroundChildLoggingId) + , mLoggingSerialNumber(aLoggingSerialNumber) + , mDatabaseId(aDatabaseId) + , mObjectStoreNames(aObjectStoreNames) + , mMode(aMode) + , mShouldFinish(false) { MOZ_ASSERT(aThreadPool); aThreadPool->AssertIsOnOwningThread(); @@ -824,9 +840,11 @@ TransactionThreadPool::TransactionQueue::Run() "TransactionThreadPool::TransactionQueue""Run", js::ProfileEntry::Category::STORAGE); - IDB_PROFILER_MARK("IndexedDB Transaction %llu: Beginning database work", - "IDBTransaction[%llu] DT Start", - mTransaction->GetSerialNumber()); + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld]: " + "Beginning database work", + "IndexedDB %s: P T[%lld]: DB Start", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mLoggingSerialNumber); nsAutoTArray, 10> queue; nsRefPtr finishCallback; @@ -877,9 +895,11 @@ TransactionThreadPool::TransactionQueue::Run() } #endif // DEBUG - IDB_PROFILER_MARK("IndexedDB Transaction %llu: Finished database work", - "IDBTransaction[%llu] DT Done", - mTransaction->GetSerialNumber()); + IDB_LOG_MARK("IndexedDB %s: Parent Transaction[%lld]: " + "Finished database work", + "IndexedDB %s: P T[%lld]: DB End", + IDB_LOG_ID_STRING(mBackgroundChildLoggingId), + mLoggingSerialNumber); nsRefPtr finishTransactionRunnable = new FinishTransactionRunnable(mOwningThreadPool.forget(), diff --git a/dom/indexedDB/TransactionThreadPool.h b/dom/indexedDB/TransactionThreadPool.h index 61c4fa0051e8..33c3c3e2d4c1 100644 --- a/dom/indexedDB/TransactionThreadPool.h +++ b/dom/indexedDB/TransactionThreadPool.h @@ -15,6 +15,7 @@ #include "nsISupportsImpl.h" #include "nsTArray.h" +struct nsID; class nsIEventTarget; class nsIRunnable; class nsIThreadPool; @@ -55,13 +56,13 @@ public: uint64_t NextTransactionId(); - void Dispatch(uint64_t aTransactionId, - const nsACString& aDatabaseId, - const nsTArray& aObjectStoreNames, - uint16_t aMode, - nsIRunnable* aRunnable, - bool aFinish, - FinishCallback* aFinishCallback); + void Start(uint64_t aTransactionId, + const nsACString& aDatabaseId, + const nsTArray& aObjectStoreNames, + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber, + nsIRunnable* aRunnable); void Dispatch(uint64_t aTransactionId, const nsACString& aDatabaseId, @@ -114,11 +115,13 @@ private: TransactionQueue* GetQueueForTransaction(uint64_t aTransactionId, const nsACString& aDatabaseId); - TransactionQueue& GetQueueForTransaction( + TransactionQueue& CreateQueueForTransaction( uint64_t aTransactionId, const nsACString& aDatabaseId, const nsTArray& aObjectStoreNames, - uint16_t aMode); + uint16_t aMode, + const nsID& aBackgroundChildLoggingId, + int64_t aLoggingSerialNumber); bool MaybeFireCallback(DatabasesCompleteCallback* aCallback); diff --git a/ipc/glue/BackgroundChildImpl.cpp b/ipc/glue/BackgroundChildImpl.cpp index 0a991a7c1f15..5a270e50fcc8 100644 --- a/ipc/glue/BackgroundChildImpl.cpp +++ b/ipc/glue/BackgroundChildImpl.cpp @@ -4,12 +4,14 @@ #include "BackgroundChildImpl.h" +#include "ActorsChild.h" // IndexedDB #include "FileDescriptorSetChild.h" #include "mozilla/Assertions.h" #include "mozilla/dom/PBlobChild.h" #include "mozilla/dom/indexedDB/PBackgroundIDBFactoryChild.h" #include "mozilla/dom/ipc/BlobChild.h" #include "mozilla/ipc/PBackgroundTestChild.h" +#include "nsID.h" #include "nsTraceRefcnt.h" namespace { @@ -48,11 +50,6 @@ namespace ipc { BackgroundChildImpl:: ThreadLocal::ThreadLocal() - : mCurrentTransaction(nullptr) -#ifdef MOZ_ENABLE_PROFILER_SPS - , mNextTransactionSerialNumber(1) - , mNextRequestSerialNumber(1) -#endif { // May happen on any thread! MOZ_COUNT_CTOR(mozilla::ipc::BackgroundChildImpl::ThreadLocal); @@ -136,7 +133,8 @@ BackgroundChildImpl::DeallocPBackgroundTestChild(PBackgroundTestChild* aActor) } BackgroundChildImpl::PBackgroundIDBFactoryChild* -BackgroundChildImpl::AllocPBackgroundIDBFactoryChild() +BackgroundChildImpl::AllocPBackgroundIDBFactoryChild( + const LoggingInfo& aLoggingInfo) { MOZ_CRASH("PBackgroundIDBFactoryChild actors should be manually " "constructed!"); diff --git a/ipc/glue/BackgroundChildImpl.h b/ipc/glue/BackgroundChildImpl.h index afdb52e8993e..0fedb67944a2 100644 --- a/ipc/glue/BackgroundChildImpl.h +++ b/ipc/glue/BackgroundChildImpl.h @@ -7,14 +7,13 @@ #include "mozilla/Attributes.h" #include "mozilla/ipc/PBackgroundChild.h" - -template class nsAutoPtr; +#include "nsAutoPtr.h" namespace mozilla { namespace dom { namespace indexedDB { -class IDBTransaction; +class ThreadLocal; } // namespace indexedDB } // namespace dom @@ -53,7 +52,7 @@ protected: DeallocPBackgroundTestChild(PBackgroundTestChild* aActor) MOZ_OVERRIDE; virtual PBackgroundIDBFactoryChild* - AllocPBackgroundIDBFactoryChild() MOZ_OVERRIDE; + AllocPBackgroundIDBFactoryChild(const LoggingInfo& aLoggingInfo) MOZ_OVERRIDE; virtual bool DeallocPBackgroundIDBFactoryChild(PBackgroundIDBFactoryChild* aActor) @@ -78,12 +77,7 @@ class BackgroundChildImpl::ThreadLocal MOZ_FINAL friend class nsAutoPtr; public: - mozilla::dom::indexedDB::IDBTransaction* mCurrentTransaction; - -#ifdef MOZ_ENABLE_PROFILER_SPS - uint64_t mNextTransactionSerialNumber; - uint64_t mNextRequestSerialNumber; -#endif + nsAutoPtr mIndexedDBThreadLocal; public: ThreadLocal(); diff --git a/ipc/glue/BackgroundParentImpl.cpp b/ipc/glue/BackgroundParentImpl.cpp index 1dd7cbedb56f..0d5eeb2d5a35 100644 --- a/ipc/glue/BackgroundParentImpl.cpp +++ b/ipc/glue/BackgroundParentImpl.cpp @@ -119,7 +119,8 @@ BackgroundParentImpl::DeallocPBackgroundTestParent( } auto -BackgroundParentImpl::AllocPBackgroundIDBFactoryParent() +BackgroundParentImpl::AllocPBackgroundIDBFactoryParent( + const LoggingInfo& aLoggingInfo) -> PBackgroundIDBFactoryParent* { using mozilla::dom::indexedDB::AllocPBackgroundIDBFactoryParent; @@ -127,12 +128,13 @@ BackgroundParentImpl::AllocPBackgroundIDBFactoryParent() AssertIsInMainProcess(); AssertIsOnBackgroundThread(); - return AllocPBackgroundIDBFactoryParent(); + return AllocPBackgroundIDBFactoryParent(aLoggingInfo); } bool BackgroundParentImpl::RecvPBackgroundIDBFactoryConstructor( - PBackgroundIDBFactoryParent* aActor) + PBackgroundIDBFactoryParent* aActor, + const LoggingInfo& aLoggingInfo) { using mozilla::dom::indexedDB::RecvPBackgroundIDBFactoryConstructor; @@ -140,18 +142,20 @@ BackgroundParentImpl::RecvPBackgroundIDBFactoryConstructor( AssertIsOnBackgroundThread(); MOZ_ASSERT(aActor); - return RecvPBackgroundIDBFactoryConstructor(aActor); + return RecvPBackgroundIDBFactoryConstructor(aActor, aLoggingInfo); } bool BackgroundParentImpl::DeallocPBackgroundIDBFactoryParent( PBackgroundIDBFactoryParent* aActor) { + using mozilla::dom::indexedDB::DeallocPBackgroundIDBFactoryParent; + AssertIsInMainProcess(); AssertIsOnBackgroundThread(); MOZ_ASSERT(aActor); - return mozilla::dom::indexedDB::DeallocPBackgroundIDBFactoryParent(aActor); + return DeallocPBackgroundIDBFactoryParent(aActor); } auto diff --git a/ipc/glue/BackgroundParentImpl.h b/ipc/glue/BackgroundParentImpl.h index ba9e78bd07ec..e0a6d7240e09 100644 --- a/ipc/glue/BackgroundParentImpl.h +++ b/ipc/glue/BackgroundParentImpl.h @@ -33,10 +33,12 @@ protected: DeallocPBackgroundTestParent(PBackgroundTestParent* aActor) MOZ_OVERRIDE; virtual PBackgroundIDBFactoryParent* - AllocPBackgroundIDBFactoryParent() MOZ_OVERRIDE; + AllocPBackgroundIDBFactoryParent(const LoggingInfo& aLoggingInfo) + MOZ_OVERRIDE; virtual bool - RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor) + RecvPBackgroundIDBFactoryConstructor(PBackgroundIDBFactoryParent* aActor, + const LoggingInfo& aLoggingInfo) MOZ_OVERRIDE; virtual bool diff --git a/ipc/glue/PBackground.ipdl b/ipc/glue/PBackground.ipdl index 89756c3410aa..4f4a155589e2 100644 --- a/ipc/glue/PBackground.ipdl +++ b/ipc/glue/PBackground.ipdl @@ -8,6 +8,7 @@ include protocol PBlob; include protocol PFileDescriptorSet; include DOMTypes; +include PBackgroundIDBSharedTypes; namespace mozilla { namespace ipc { @@ -23,7 +24,7 @@ parent: // Only called at startup during mochitests to check the basic infrastructure. PBackgroundTest(nsCString testArg); - PBackgroundIDBFactory(); + PBackgroundIDBFactory(LoggingInfo loggingInfo); both: PBlob(BlobConstructorParams params); diff --git a/ipc/glue/moz.build b/ipc/glue/moz.build index b4e2b68ca377..6ea3abfd87b1 100644 --- a/ipc/glue/moz.build +++ b/ipc/glue/moz.build @@ -130,6 +130,7 @@ SOURCES += [ ] LOCAL_INCLUDES += [ + '/dom/indexedDB', '/xpcom/build', ] diff --git a/modules/libpref/init/all.js b/modules/libpref/init/all.js index 6974671d762b..7e13a89e8ce4 100644 --- a/modules/libpref/init/all.js +++ b/modules/libpref/init/all.js @@ -119,6 +119,12 @@ pref("dom.indexedDB.enabled", true); pref("dom.indexedDB.warningQuota", 50); // Whether or not indexedDB experimental features are enabled. pref("dom.indexedDB.experimental", false); +// Enable indexedDB logging. +pref("dom.indexedDB.logging.enabled", true); +// Detailed output in log messages. +pref("dom.indexedDB.logging.details", true); +// Enable profiler marks for indexedDB events. +pref("dom.indexedDB.logging.profiler-marks", false); // Whether or not Web Workers are enabled. pref("dom.workers.enabled", true);