diff --git a/netwerk/cache2/CacheEntry.cpp b/netwerk/cache2/CacheEntry.cpp index 32082d60d9a1..3a5685cc56de 100644 --- a/netwerk/cache2/CacheEntry.cpp +++ b/netwerk/cache2/CacheEntry.cpp @@ -21,6 +21,7 @@ #include "nsProxyRelease.h" #include "nsSerializationHelper.h" #include "nsThreadUtils.h" +#include "mozilla/Telemetry.h" #include #include @@ -215,6 +216,7 @@ bool CacheEntry::Load(bool aTruncate, bool aPriority) } else { mState = LOADING; + mLoadStart = TimeStamp::Now(); } mFile = new CacheFile(); @@ -252,6 +254,21 @@ NS_IMETHODIMP CacheEntry::OnFileReady(nsresult aResult, bool aIsNew) LOG(("CacheEntry::OnFileReady [this=%p, rv=0x%08x, new=%d]", this, aResult, aIsNew)); + MOZ_ASSERT(!mLoadStart.IsNull()); + + if (NS_SUCCEEDED(aResult)) { + if (aIsNew) { + mozilla::Telemetry::AccumulateTimeDelta( + mozilla::Telemetry::NETWORK_CACHE_V2_MISS_TIME_MS, + mLoadStart); + } + else { + mozilla::Telemetry::AccumulateTimeDelta( + mozilla::Telemetry::NETWORK_CACHE_V2_HIT_TIME_MS, + mLoadStart); + } + } + // OnFileReady, that is the only code that can transit from LOADING // to any follow-on state, can only be invoked ones on an entry, // thus no need to lock. Until this moment there is no consumer that diff --git a/netwerk/cache2/CacheEntry.h b/netwerk/cache2/CacheEntry.h index 7f4ea3e81f9c..ea294b2ece77 100644 --- a/netwerk/cache2/CacheEntry.h +++ b/netwerk/cache2/CacheEntry.h @@ -21,6 +21,7 @@ #include "nsCOMArray.h" #include "nsThreadUtils.h" #include "mozilla/Mutex.h" +#include "mozilla/TimeStamp.h" static inline uint32_t PRTimeToSeconds(PRTime t_usec) @@ -293,6 +294,8 @@ private: int64_t mPredictedDataSize; uint32_t mDataSize; // ??? + + mozilla::TimeStamp mLoadStart; }; } // net diff --git a/netwerk/cache2/OldWrappers.cpp b/netwerk/cache2/OldWrappers.cpp index 8ff43c3fd27b..cd52199b2a0b 100644 --- a/netwerk/cache2/OldWrappers.cpp +++ b/netwerk/cache2/OldWrappers.cpp @@ -20,6 +20,7 @@ #include "nsServiceManagerUtils.h" #include "nsNetCID.h" #include "nsProxyRelease.h" +#include "mozilla/Telemetry.h" static NS_DEFINE_CID(kStreamTransportServiceCID, NS_STREAMTRANSPORTSERVICE_CID); @@ -485,6 +486,8 @@ nsresult _OldCacheLoad::Start() LOG(("_OldCacheLoad::Start [this=%p, key=%s]", this, mCacheKey.get())); MOZ_ASSERT(NS_IsMainThread()); + mLoadStart = mozilla::TimeStamp::Now(); + bool mainThreadOnly; if (mCallback && ( NS_SUCCEEDED(mCallback->GetMainThreadOnly(&mainThreadOnly)) && @@ -558,6 +561,24 @@ _OldCacheLoad::Run() return NS_OK; } + if (NS_SUCCEEDED(mStatus)) { + if (mFlags & nsICacheStorage::OPEN_TRUNCATE) { + mozilla::Telemetry::AccumulateTimeDelta( + mozilla::Telemetry::NETWORK_CACHE_V1_TRUNCATE_TIME_MS, + mLoadStart); + } + else if (mNew) { + mozilla::Telemetry::AccumulateTimeDelta( + mozilla::Telemetry::NETWORK_CACHE_V1_MISS_TIME_MS, + mLoadStart); + } + else { + mozilla::Telemetry::AccumulateTimeDelta( + mozilla::Telemetry::NETWORK_CACHE_V1_HIT_TIME_MS, + mLoadStart); + } + } + if (mMainThreadOnly) Check(); diff --git a/netwerk/cache2/OldWrappers.h b/netwerk/cache2/OldWrappers.h index 3946bcb51d0d..8b1eb4416bf2 100644 --- a/netwerk/cache2/OldWrappers.h +++ b/netwerk/cache2/OldWrappers.h @@ -11,6 +11,7 @@ #include "nsICacheEntryOpenCallback.h" #include "nsICacheEntryDescriptor.h" #include "nsThreadUtils.h" +#include "mozilla/TimeStamp.h" class nsIURI; class nsICacheEntryOpenCallback; @@ -88,6 +89,8 @@ private: nsresult mStatus; uint32_t mRunCount; nsCOMPtr mAppCache; + + mozilla::TimeStamp mLoadStart; }; diff --git a/toolkit/components/telemetry/Histograms.json b/toolkit/components/telemetry/Histograms.json index ddf2a0fec4ca..17a597d1fee6 100644 --- a/toolkit/components/telemetry/Histograms.json +++ b/toolkit/components/telemetry/Histograms.json @@ -4014,5 +4014,40 @@ "n_buckets": 15, "extended_statistics_ok": true, "description": "BACKGROUND THUMBNAILS: Time it took to draw the capture's window to canvas (ms)" + }, + "NETWORK_CACHE_V2_MISS_TIME_MS": { + "kind": "exponential", + "high": "10000", + "n_buckets": 50, + "extended_statistics_ok": true, + "description": "Time spent to find out a cache entry file is missing" + }, + "NETWORK_CACHE_V2_HIT_TIME_MS": { + "kind": "exponential", + "high": "10000", + "n_buckets": 50, + "extended_statistics_ok": true, + "description": "Time spent to open an existing file" + }, + "NETWORK_CACHE_V1_TRUNCATE_TIME_MS": { + "kind": "exponential", + "high": "10000", + "n_buckets": 50, + "extended_statistics_ok": true, + "description": "Time spent to reopen an entry with OPEN_TRUNCATE" + }, + "NETWORK_CACHE_V1_MISS_TIME_MS": { + "kind": "exponential", + "high": "10000", + "n_buckets": 50, + "extended_statistics_ok": true, + "description": "Time spent to find out a cache entry is missing" + }, + "NETWORK_CACHE_V1_HIT_TIME_MS": { + "kind": "exponential", + "high": "10000", + "n_buckets": 50, + "extended_statistics_ok": true, + "description": "Time spent to open an existing cache entry" } }