Bug 1857217 - Understand the IPC delays introduced by socket process, r=acreskey,necko-reviewers,valentin

Differential Revision: https://phabricator.services.mozilla.com/D190182
This commit is contained in:
Kershaw Chang 2023-10-10 15:09:18 +00:00
parent 6442aff82b
commit ff5a7836c1
22 changed files with 283 additions and 124 deletions

View File

@ -21,7 +21,8 @@ void BackgroundDataBridgeChild::ActorDestroy(ActorDestroyReason aWhy) {
}
mozilla::ipc::IPCResult BackgroundDataBridgeChild::RecvOnTransportAndData(
const uint64_t& offset, const uint32_t& count, const nsACString& data) {
const uint64_t& offset, const uint32_t& count, const nsACString& data,
const TimeStamp& aOnDataAvailableStartTime) {
if (!mBgChild) {
return IPC_OK();
}
@ -32,13 +33,15 @@ mozilla::ipc::IPCResult BackgroundDataBridgeChild::RecvOnTransportAndData(
}
return mBgChild->RecvOnTransportAndData(NS_OK, NS_NET_STATUS_RECEIVING_FROM,
offset, count, data, true);
offset, count, data, true,
aOnDataAvailableStartTime);
}
mozilla::ipc::IPCResult BackgroundDataBridgeChild::RecvOnStopRequest(
nsresult aStatus, const ResourceTimingStructArgs& aTiming,
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers) {
const nsHttpHeaderArray& aResponseTrailers,
const TimeStamp& aOnStopRequestStartTime) {
if (!mBgChild) {
return IPC_OK();
}
@ -48,9 +51,9 @@ mozilla::ipc::IPCResult BackgroundDataBridgeChild::RecvOnStopRequest(
return IPC_OK();
}
return mBgChild->RecvOnStopRequest(aStatus, aTiming, aLastActiveTabOptHit,
aResponseTrailers,
nsTArray<ConsoleReportCollected>(), true);
return mBgChild->RecvOnStopRequest(
aStatus, aTiming, aLastActiveTabOptHit, aResponseTrailers,
nsTArray<ConsoleReportCollected>(), true, aOnStopRequestStartTime);
}
} // namespace net

View File

@ -25,13 +25,14 @@ class BackgroundDataBridgeChild final : public PBackgroundDataBridgeChild {
RefPtr<HttpBackgroundChannelChild> mBgChild;
public:
mozilla::ipc::IPCResult RecvOnTransportAndData(const uint64_t& offset,
const uint32_t& count,
const nsACString& data);
mozilla::ipc::IPCResult RecvOnTransportAndData(
const uint64_t& offset, const uint32_t& count, const nsACString& data,
const TimeStamp& aOnDataAvailableStartTime);
mozilla::ipc::IPCResult RecvOnStopRequest(
nsresult aStatus, const ResourceTimingStructArgs& aTiming,
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers);
const nsHttpHeaderArray& aResponseTrailers,
const TimeStamp& aOnStopRequestStartTime);
};
} // namespace net

View File

@ -42,18 +42,20 @@ void BackgroundDataBridgeParent::Destroy() {
void BackgroundDataBridgeParent::OnStopRequest(
nsresult aStatus, const ResourceTimingStructArgs& aTiming,
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers) {
const nsHttpHeaderArray& aResponseTrailers,
const TimeStamp& aOnStopRequestStart) {
RefPtr<BackgroundDataBridgeParent> self = this;
MOZ_ALWAYS_SUCCEEDS(mBackgroundThread->Dispatch(
NS_NewRunnableFunction(
"BackgroundDataBridgeParent::OnStopRequest",
[self, aStatus, aTiming, aLastActiveTabOptHit, aResponseTrailers]() {
if (self->CanSend()) {
Unused << self->SendOnStopRequest(
aStatus, aTiming, aLastActiveTabOptHit, aResponseTrailers);
self->Close();
}
}),
NS_NewRunnableFunction("BackgroundDataBridgeParent::OnStopRequest",
[self, aStatus, aTiming, aLastActiveTabOptHit,
aResponseTrailers, aOnStopRequestStart]() {
if (self->CanSend()) {
Unused << self->SendOnStopRequest(
aStatus, aTiming, aLastActiveTabOptHit,
aResponseTrailers, aOnStopRequestStart);
self->Close();
}
}),
NS_DISPATCH_NORMAL));
}

View File

@ -20,7 +20,8 @@ class BackgroundDataBridgeParent final : public PBackgroundDataBridgeParent {
void Destroy();
void OnStopRequest(nsresult aStatus, const ResourceTimingStructArgs& aTiming,
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers);
const nsHttpHeaderArray& aResponseTrailers,
const TimeStamp& aOnStopRequestStart);
private:
virtual ~BackgroundDataBridgeParent() = default;

View File

@ -185,7 +185,8 @@ IPCResult HttpBackgroundChannelChild::RecvOnStartRequest(
const nsHttpResponseHead& aResponseHead, const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const HttpChannelAltDataStream& aAltData) {
const HttpChannelAltDataStream& aAltData,
const TimeStamp& aOnStartRequestStart) {
LOG((
"HttpBackgroundChannelChild::RecvOnStartRequest [this=%p, status=%" PRIx32
"]\n",
@ -200,7 +201,8 @@ IPCResult HttpBackgroundChannelChild::RecvOnStartRequest(
aArgs.dataFromSocketProcess() ? ODA_FROM_SOCKET : ODA_FROM_PARENT;
mChannelChild->ProcessOnStartRequest(aResponseHead, aUseResponseHead,
aRequestHeaders, aArgs, aAltData);
aRequestHeaders, aArgs, aAltData,
aOnStartRequestStart);
// Allow to queue other runnable since OnStartRequest Event already hits the
// child's mEventQ.
OnStartRequestReceived(aArgs.multiPartID());
@ -211,11 +213,13 @@ IPCResult HttpBackgroundChannelChild::RecvOnStartRequest(
IPCResult HttpBackgroundChannelChild::RecvOnTransportAndData(
const nsresult& aChannelStatus, const nsresult& aTransportStatus,
const uint64_t& aOffset, const uint32_t& aCount, const nsACString& aData,
const bool& aDataFromSocketProcess) {
const bool& aDataFromSocketProcess,
const TimeStamp& aOnDataAvailableStart) {
RefPtr<HttpBackgroundChannelChild> self = this;
std::function<void()> callProcessOnTransportAndData =
[self, aChannelStatus, aTransportStatus, aOffset, aCount,
data = nsCString(aData), aDataFromSocketProcess]() {
data = nsCString(aData), aDataFromSocketProcess,
aOnDataAvailableStart]() {
LOG(
("HttpBackgroundChannelChild::RecvOnTransportAndData [this=%p, "
"aDataFromSocketProcess=%d, mFirstODASource=%d]\n",
@ -243,7 +247,8 @@ IPCResult HttpBackgroundChannelChild::RecvOnTransportAndData(
}
self->mChannelChild->ProcessOnTransportAndData(
aChannelStatus, aTransportStatus, aOffset, aCount, data);
aChannelStatus, aTransportStatus, aOffset, aCount, data,
aOnDataAvailableStart);
};
// Bug 1641336: Race only happens if the data is from socket process.
@ -267,7 +272,7 @@ IPCResult HttpBackgroundChannelChild::RecvOnStopRequest(
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers,
nsTArray<ConsoleReportCollected>&& aConsoleReports,
const bool& aFromSocketProcess) {
const bool& aFromSocketProcess, const TimeStamp& aOnStopRequestStart) {
LOG(
("HttpBackgroundChannelChild::RecvOnStopRequest [this=%p, "
"aFromSocketProcess=%d, mFirstODASource=%d]\n",
@ -295,10 +300,10 @@ IPCResult HttpBackgroundChannelChild::RecvOnStopRequest(
"HttpBackgroundChannelChild::RecvOnStopRequest",
[self, aChannelStatus, aTiming, aLastActiveTabOptHit, aResponseTrailers,
consoleReports = CopyableTArray{std::move(aConsoleReports)},
aFromSocketProcess]() mutable {
aFromSocketProcess, aOnStopRequestStart]() mutable {
self->RecvOnStopRequest(aChannelStatus, aTiming, aLastActiveTabOptHit,
aResponseTrailers, std::move(consoleReports),
aFromSocketProcess);
aFromSocketProcess, aOnStopRequestStart);
});
mQueuedRunnables.AppendElement(task.forget());
@ -308,9 +313,9 @@ IPCResult HttpBackgroundChannelChild::RecvOnStopRequest(
if (mFirstODASource != ODA_FROM_SOCKET) {
if (!aFromSocketProcess) {
mOnStopRequestCalled = true;
mChannelChild->ProcessOnStopRequest(aChannelStatus, aTiming,
aResponseTrailers,
std::move(aConsoleReports), false);
mChannelChild->ProcessOnStopRequest(
aChannelStatus, aTiming, aResponseTrailers,
std::move(aConsoleReports), false, aOnStopRequestStart);
}
return IPC_OK();
}
@ -320,9 +325,9 @@ IPCResult HttpBackgroundChannelChild::RecvOnStopRequest(
if (aFromSocketProcess) {
MOZ_ASSERT(!mOnStopRequestCalled);
mOnStopRequestCalled = true;
mChannelChild->ProcessOnStopRequest(aChannelStatus, aTiming,
aResponseTrailers,
std::move(aConsoleReports), true);
mChannelChild->ProcessOnStopRequest(
aChannelStatus, aTiming, aResponseTrailers, std::move(aConsoleReports),
true, aOnStopRequestStart);
if (mConsoleReportTask) {
mConsoleReportTask();
mConsoleReportTask = nullptr;

View File

@ -57,21 +57,23 @@ class HttpBackgroundChannelChild final : public PHttpBackgroundChannelChild {
const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const HttpChannelAltDataStream& aAltData);
const HttpChannelAltDataStream& aAltData,
const TimeStamp& aOnStartRequestStart);
IPCResult RecvOnTransportAndData(const nsresult& aChannelStatus,
const nsresult& aTransportStatus,
const uint64_t& aOffset,
const uint32_t& aCount,
const nsACString& aData,
const bool& aDataFromSocketProcess);
const bool& aDataFromSocketProcess,
const TimeStamp& aOnDataAvailableStart);
IPCResult RecvOnStopRequest(
const nsresult& aChannelStatus, const ResourceTimingStructArgs& aTiming,
const TimeStamp& aLastActiveTabOptHit,
const nsHttpHeaderArray& aResponseTrailers,
nsTArray<ConsoleReportCollected>&& aConsoleReports,
const bool& aFromSocketProcess);
const bool& aFromSocketProcess, const TimeStamp& aOnStopRequestStart);
IPCResult RecvOnConsoleReport(
nsTArray<ConsoleReportCollected>&& aConsoleReports);

View File

@ -147,7 +147,8 @@ bool HttpBackgroundChannelParent::OnStartRequest(
const nsHttpResponseHead& aResponseHead, const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const nsCOMPtr<nsICacheEntry>& aAltDataSource) {
const nsCOMPtr<nsICacheEntry>& aAltDataSource,
TimeStamp aOnStartRequestStart) {
LOG(("HttpBackgroundChannelParent::OnStartRequest [this=%p]\n", this));
AssertIsInMainProcess();
@ -158,12 +159,14 @@ bool HttpBackgroundChannelParent::OnStartRequest(
if (!IsOnBackgroundThread()) {
MutexAutoLock lock(mBgThreadMutex);
nsresult rv = mBackgroundThread->Dispatch(
NewRunnableMethod<
const nsHttpResponseHead, const bool, const nsHttpHeaderArray,
const HttpChannelOnStartRequestArgs, const nsCOMPtr<nsICacheEntry>>(
NewRunnableMethod<const nsHttpResponseHead, const bool,
const nsHttpHeaderArray,
const HttpChannelOnStartRequestArgs,
const nsCOMPtr<nsICacheEntry>, TimeStamp>(
"net::HttpBackgroundChannelParent::OnStartRequest", this,
&HttpBackgroundChannelParent::OnStartRequest, aResponseHead,
aUseResponseHead, aRequestHeaders, aArgs, aAltDataSource),
aUseResponseHead, aRequestHeaders, aArgs, aAltDataSource,
aOnStartRequestStart),
NS_DISPATCH_NORMAL);
MOZ_DIAGNOSTIC_ASSERT(NS_SUCCEEDED(rv));
@ -189,12 +192,13 @@ bool HttpBackgroundChannelParent::OnStartRequest(
}
return SendOnStartRequest(aResponseHead, aUseResponseHead, aRequestHeaders,
aArgs, altData);
aArgs, altData, aOnStartRequestStart);
}
bool HttpBackgroundChannelParent::OnTransportAndData(
const nsresult& aChannelStatus, const nsresult& aTransportStatus,
const uint64_t& aOffset, const uint32_t& aCount, const nsCString& aData) {
const uint64_t& aOffset, const uint32_t& aCount, const nsCString& aData,
TimeStamp aOnDataAvailableStart) {
LOG(("HttpBackgroundChannelParent::OnTransportAndData [this=%p]\n", this));
AssertIsInMainProcess();
@ -206,10 +210,10 @@ bool HttpBackgroundChannelParent::OnTransportAndData(
MutexAutoLock lock(mBgThreadMutex);
nsresult rv = mBackgroundThread->Dispatch(
NewRunnableMethod<const nsresult, const nsresult, const uint64_t,
const uint32_t, const nsCString>(
const uint32_t, const nsCString, TimeStamp>(
"net::HttpBackgroundChannelParent::OnTransportAndData", this,
&HttpBackgroundChannelParent::OnTransportAndData, aChannelStatus,
aTransportStatus, aOffset, aCount, aData),
aTransportStatus, aOffset, aCount, aData, aOnDataAvailableStart),
NS_DISPATCH_NORMAL);
MOZ_DIAGNOSTIC_ASSERT(NS_SUCCEEDED(rv));
@ -219,10 +223,12 @@ bool HttpBackgroundChannelParent::OnTransportAndData(
nsHttp::SendFunc<nsDependentCSubstring> sendFunc =
[self = UnsafePtr<HttpBackgroundChannelParent>(this), aChannelStatus,
aTransportStatus](const nsDependentCSubstring& aData, uint64_t aOffset,
uint32_t aCount) {
aTransportStatus,
aOnDataAvailableStart](const nsDependentCSubstring& aData,
uint64_t aOffset, uint32_t aCount) {
return self->SendOnTransportAndData(aChannelStatus, aTransportStatus,
aOffset, aCount, aData, false);
aOffset, aCount, aData, false,
aOnDataAvailableStart);
};
return nsHttp::SendDataInChunks(aData, aOffset, aCount, sendFunc);
@ -231,7 +237,8 @@ bool HttpBackgroundChannelParent::OnTransportAndData(
bool HttpBackgroundChannelParent::OnStopRequest(
const nsresult& aChannelStatus, const ResourceTimingStructArgs& aTiming,
const nsHttpHeaderArray& aResponseTrailers,
const nsTArray<ConsoleReportCollected>& aConsoleReports) {
const nsTArray<ConsoleReportCollected>& aConsoleReports,
TimeStamp aOnStopRequestStart) {
LOG(
("HttpBackgroundChannelParent::OnStopRequest [this=%p "
"status=%" PRIx32 "]\n",
@ -247,10 +254,11 @@ bool HttpBackgroundChannelParent::OnStopRequest(
nsresult rv = mBackgroundThread->Dispatch(
NewRunnableMethod<const nsresult, const ResourceTimingStructArgs,
const nsHttpHeaderArray,
const CopyableTArray<ConsoleReportCollected>>(
const CopyableTArray<ConsoleReportCollected>,
TimeStamp>(
"net::HttpBackgroundChannelParent::OnStopRequest", this,
&HttpBackgroundChannelParent::OnStopRequest, aChannelStatus,
aTiming, aResponseTrailers, aConsoleReports),
aTiming, aResponseTrailers, aConsoleReports, aOnStopRequestStart),
NS_DISPATCH_NORMAL);
MOZ_DIAGNOSTIC_ASSERT(NS_SUCCEEDED(rv));
@ -262,7 +270,8 @@ bool HttpBackgroundChannelParent::OnStopRequest(
TimeStamp lastActTabOpt = nsHttp::GetLastActiveTabLoadOptimizationHit();
return SendOnStopRequest(aChannelStatus, aTiming, lastActTabOpt,
aResponseTrailers, aConsoleReports, false);
aResponseTrailers, aConsoleReports, false,
aOnStopRequestStart);
}
bool HttpBackgroundChannelParent::OnConsoleReport(

View File

@ -44,19 +44,22 @@ class HttpBackgroundChannelParent final : public PHttpBackgroundChannelParent {
const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const nsCOMPtr<nsICacheEntry>& aCacheEntry);
const nsCOMPtr<nsICacheEntry>& aCacheEntry,
TimeStamp aOnStartRequestStart);
// To send OnTransportAndData message over background channel.
bool OnTransportAndData(const nsresult& aChannelStatus,
const nsresult& aTransportStatus,
const uint64_t& aOffset, const uint32_t& aCount,
const nsCString& aData);
const nsCString& aData,
TimeStamp aOnDataAvailableStart);
// To send OnStopRequest message over background channel.
bool OnStopRequest(const nsresult& aChannelStatus,
const ResourceTimingStructArgs& aTiming,
const nsHttpHeaderArray& aResponseTrailers,
const nsTArray<ConsoleReportCollected>& aConsoleReports);
const nsTArray<ConsoleReportCollected>& aConsoleReports,
TimeStamp aOnStopRequestStart);
// When ODA and OnStopRequest are sending from socket process to child
// process, this is the last IPC message sent from parent process.

View File

@ -572,6 +572,16 @@ class HttpBaseChannel : public nsHashPropertyBag,
return mCachedOpaqueResponseBlockingPref;
}
TimeStamp GetOnStartRequestStartTime() const {
return mOnStartRequestStartTime;
}
TimeStamp GetDataAvailableStartTime() const {
return mOnDataAvailableStartTime;
}
TimeStamp GetOnStopRequestStartTime() const {
return mOnStopRequestStartTime;
}
protected:
nsresult GetTopWindowURI(nsIURI* aURIBeingLoaded, nsIURI** aTopWindowURI);
@ -784,6 +794,9 @@ class HttpBaseChannel : public nsHashPropertyBag,
TimeStamp mDispatchFetchEventEnd;
TimeStamp mHandleFetchEventStart;
TimeStamp mHandleFetchEventEnd;
TimeStamp mOnStartRequestStartTime;
TimeStamp mOnDataAvailableStartTime;
TimeStamp mOnStopRequestStartTime;
// copied from the transaction before we null out mTransaction
// so that the timing can still be queried from OnStopRequest
TimingStruct mTransactionTimings;

View File

@ -347,15 +347,18 @@ void HttpChannelChild::ProcessOnStartRequest(
const nsHttpResponseHead& aResponseHead, const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const HttpChannelAltDataStream& aAltData) {
const HttpChannelAltDataStream& aAltData,
const TimeStamp& aOnStartRequestStartTime) {
LOG(("HttpChannelChild::ProcessOnStartRequest [this=%p]\n", this));
MOZ_ASSERT(OnSocketThread());
mAltDataInputStream = DeserializeIPCStream(aAltData.altDataInputStream());
mEventQ->RunOrEnqueue(new NeckoTargetChannelFunctionEvent(
this, [self = UnsafePtr<HttpChannelChild>(this), aResponseHead,
aUseResponseHead, aRequestHeaders, aArgs]() {
this,
[self = UnsafePtr<HttpChannelChild>(this), aResponseHead,
aUseResponseHead, aRequestHeaders, aArgs, aOnStartRequestStartTime]() {
self->mOnStartRequestStartTime = aOnStartRequestStartTime;
self->OnStartRequest(aResponseHead, aUseResponseHead, aRequestHeaders,
aArgs);
}));
@ -460,13 +463,18 @@ void HttpChannelChild::OnStartRequest(
aArgs.timing().transactionPending() - mAsyncOpenTime);
}
const TimeStamp now = TimeStamp::Now();
if (!aArgs.timing().responseStart().IsNull()) {
Telemetry::AccumulateTimeDelta(
Telemetry::NETWORK_RESPONSE_START_PARENT_TO_CONTENT_EXP_MS, cosString,
aArgs.timing().responseStart(), TimeStamp::Now());
aArgs.timing().responseStart(), now);
PerfStats::RecordMeasurement(
PerfStats::Metric::HttpChannelResponseStartParentToContent,
TimeStamp::Now() - aArgs.timing().responseStart());
now - aArgs.timing().responseStart());
}
if (!mOnStartRequestStartTime.IsNull()) {
PerfStats::RecordMeasurement(PerfStats::Metric::OnStartRequestToContent,
now - mOnStartRequestStartTime);
}
StoreAllRedirectsSameOrigin(aArgs.allRedirectsSameOrigin());
@ -601,7 +609,8 @@ void HttpChannelChild::DoOnStartRequest(nsIRequest* aRequest) {
void HttpChannelChild::ProcessOnTransportAndData(
const nsresult& aChannelStatus, const nsresult& aTransportStatus,
const uint64_t& aOffset, const uint32_t& aCount, const nsACString& aData) {
const uint64_t& aOffset, const uint32_t& aCount, const nsACString& aData,
const TimeStamp& aOnDataAvailableStartTime) {
LOG(("HttpChannelChild::ProcessOnTransportAndData [this=%p]\n", this));
MOZ_ASSERT(OnSocketThread());
mEventQ->RunOrEnqueue(new ChannelFunctionEvent(
@ -609,7 +618,9 @@ void HttpChannelChild::ProcessOnTransportAndData(
return self->GetODATarget();
},
[self = UnsafePtr<HttpChannelChild>(this), aChannelStatus,
aTransportStatus, aOffset, aCount, aData = nsCString(aData)]() {
aTransportStatus, aOffset, aCount, aData = nsCString(aData),
aOnDataAvailableStartTime]() {
self->mOnDataAvailableStartTime = aOnDataAvailableStartTime;
self->OnTransportAndData(aChannelStatus, aTransportStatus, aOffset,
aCount, aData);
}));
@ -630,6 +641,11 @@ void HttpChannelChild::OnTransportAndData(const nsresult& aChannelStatus,
return;
}
if (!mOnDataAvailableStartTime.IsNull()) {
PerfStats::RecordMeasurement(PerfStats::Metric::OnDataAvailableToContent,
TimeStamp::Now() - mOnDataAvailableStartTime);
}
// Hold queue lock throughout all three calls, else we might process a later
// necko msg in between them.
AutoEventEnqueuer ensureSerialDispatch(mEventQ);
@ -788,8 +804,8 @@ void HttpChannelChild::DoOnDataAvailable(nsIRequest* aRequest,
void HttpChannelChild::ProcessOnStopRequest(
const nsresult& aChannelStatus, const ResourceTimingStructArgs& aTiming,
const nsHttpHeaderArray& aResponseTrailers,
nsTArray<ConsoleReportCollected>&& aConsoleReports,
bool aFromSocketProcess) {
nsTArray<ConsoleReportCollected>&& aConsoleReports, bool aFromSocketProcess,
const TimeStamp& aOnStopRequestStartTime) {
LOG(
("HttpChannelChild::ProcessOnStopRequest [this=%p, "
"aFromSocketProcess=%d]\n",
@ -800,7 +816,8 @@ void HttpChannelChild::ProcessOnStopRequest(
this, [self = UnsafePtr<HttpChannelChild>(this), aChannelStatus, aTiming,
aResponseTrailers,
consoleReports = CopyableTArray{aConsoleReports.Clone()},
aFromSocketProcess]() mutable {
aFromSocketProcess, aOnStopRequestStartTime]() mutable {
self->mOnStopRequestStartTime = aOnStopRequestStartTime;
self->OnStopRequest(aChannelStatus, aTiming, aResponseTrailers);
if (!aFromSocketProcess) {
self->DoOnConsoleReport(std::move(consoleReports));
@ -959,6 +976,11 @@ void HttpChannelChild::OnStopRequest(
now - aTiming.responseEnd());
}
if (!mOnStopRequestStartTime.IsNull()) {
PerfStats::RecordMeasurement(PerfStats::Metric::OnStopRequestToContent,
now - mOnStopRequestStartTime);
}
mResponseTrailers = MakeUnique<nsHttpHeaderArray>(aResponseTrailers);
DoPreOnStopRequest(aChannelStatus);

View File

@ -208,7 +208,8 @@ class HttpChannelChild final : public PHttpChannelChild,
const bool& aUseResponseHead,
const nsHttpHeaderArray& aRequestHeaders,
const HttpChannelOnStartRequestArgs& aArgs,
const HttpChannelAltDataStream& aAltData);
const HttpChannelAltDataStream& aAltData,
const TimeStamp& aOnStartRequestStartTime);
// Callbacks while receiving OnTransportAndData/OnStopRequest/OnProgress/
// OnStatus/FlushedForDiversion/DivertMessages on background IPC channel.
@ -216,12 +217,14 @@ class HttpChannelChild final : public PHttpChannelChild,
const nsresult& aTransportStatus,
const uint64_t& aOffset,
const uint32_t& aCount,
const nsACString& aData);
const nsACString& aData,
const TimeStamp& aOnDataAvailableStartTime);
void ProcessOnStopRequest(const nsresult& aChannelStatus,
const ResourceTimingStructArgs& aTiming,
const nsHttpHeaderArray& aResponseTrailers,
nsTArray<ConsoleReportCollected>&& aConsoleReports,
bool aFromSocketProcess);
bool aFromSocketProcess,
const TimeStamp& aOnStopRequestStartTime);
void ProcessOnConsoleReport(
nsTArray<ConsoleReportCollected>&& aConsoleReports);

View File

@ -1333,7 +1333,7 @@ HttpChannelParent::OnStartRequest(nsIRequest* aRequest) {
!mBgParent->OnStartRequest(
*responseHead, useResponseHead,
cleanedUpRequest ? cleanedUpRequestHeaders : requestHead->Headers(),
args, altDataSource)) {
args, altDataSource, chan->GetOnStartRequestStartTime())) {
rv = NS_ERROR_UNEXPECTED;
}
requestHead->Exit();
@ -1382,8 +1382,10 @@ HttpChannelParent::OnStopRequest(nsIRequest* aRequest, nsresult aStatusCode) {
nsTArray<ConsoleReportCollected> consoleReports;
RefPtr<HttpBaseChannel> httpChannel = do_QueryObject(mChannel);
TimeStamp onStopRequestStart;
if (httpChannel) {
httpChannel->StealConsoleReports(consoleReports);
onStopRequestStart = httpChannel->GetOnStopRequestStartTime();
}
// Either IPC channel is closed or background channel
@ -1404,7 +1406,7 @@ HttpChannelParent::OnStopRequest(nsIRequest* aRequest, nsresult aStatusCode) {
!mBgParent->OnStopRequest(
aStatusCode, GetTimingAttributes(mChannel),
responseTrailer ? *responseTrailer : nsHttpHeaderArray(),
consoleReports)) {
consoleReports, onStopRequestStart)) {
return NS_ERROR_UNEXPECTED;
}
@ -1498,10 +1500,12 @@ HttpChannelParent::OnDataAvailable(nsIRequest* aRequest,
nsresult transportStatus = NS_NET_STATUS_RECEIVING_FROM;
RefPtr<nsHttpChannel> httpChannelImpl = do_QueryObject(mChannel);
TimeStamp onDataAvailableStart = TimeStamp::Now();
if (httpChannelImpl) {
if (httpChannelImpl->IsReadingFromCache()) {
transportStatus = NS_NET_STATUS_READING;
}
onDataAvailableStart = httpChannelImpl->GetDataAvailableStartTime();
}
nsCString data;
@ -1516,7 +1520,7 @@ HttpChannelParent::OnDataAvailable(nsIRequest* aRequest,
if (mIPCClosed || !mBgParent ||
!mBgParent->OnTransportAndData(channelStatus, transportStatus, aOffset,
aCount, data)) {
aCount, data, onDataAvailableStart)) {
return NS_ERROR_UNEXPECTED;
}

View File

@ -275,7 +275,8 @@ HttpTransactionChild::OnDataAvailable(nsIRequest* aRequest,
nsHttp::SendFunc<nsCString> sendFunc =
[self = UnsafePtr<HttpTransactionChild>(this)](
const nsCString& aData, uint64_t aOffset, uint32_t aCount) {
return self->SendOnDataAvailable(aData, aOffset, aCount);
return self->SendOnDataAvailable(aData, aOffset, aCount,
TimeStamp::Now());
};
LOG((" ODA to parent process"));
@ -295,8 +296,8 @@ HttpTransactionChild::OnDataAvailable(nsIRequest* aRequest,
[self = UnsafePtr<HttpTransactionChild>(this)](
const nsDependentCSubstring& aData, uint64_t aOffset,
uint32_t aCount) {
return self->mDataBridgeParent->SendOnTransportAndData(aOffset, aCount,
aData);
return self->mDataBridgeParent->SendOnTransportAndData(
aOffset, aCount, aData, TimeStamp::Now());
};
LOG((" ODA to content process"));
@ -306,7 +307,7 @@ HttpTransactionChild::OnDataAvailable(nsIRequest* aRequest,
}
// We still need to send ODA to parent process, because the data needs to be
// saved in cache. Note that we set dataSentToChildProcess to true, to this
// saved in cache. Note that we set dataSentToChildProcess to true, so this
// ODA will not be sent to child process.
RefPtr<HttpTransactionChild> self = this;
rv = NS_DispatchToMainThread(
@ -316,7 +317,8 @@ HttpTransactionChild::OnDataAvailable(nsIRequest* aRequest,
nsHttp::SendFunc<nsCString> sendFunc =
[self](const nsCString& aData, uint64_t aOffset,
uint32_t aCount) {
return self->SendOnDataAvailable(aData, aOffset, aCount);
return self->SendOnDataAvailable(aData, aOffset, aCount,
TimeStamp::Now());
};
if (!nsHttp::SendDataInChunks(data, offset, count, sendFunc)) {
@ -485,7 +487,8 @@ HttpTransactionChild::OnStartRequest(nsIRequest* aRequest) {
ToTimingStructArgs(mTransaction->Timings()), proxyConnectResponseCode,
dataForSniffer, optionalAltSvcUsed, !!mDataBridgeParent,
mTransaction->TakeRestartedState(), mTransaction->HTTPSSVCReceivedStage(),
mTransaction->GetSupportsHTTP3(), mode, reason, mTransaction->Caps());
mTransaction->GetSupportsHTTP3(), mode, reason, mTransaction->Caps(),
TimeStamp::Now());
return NS_OK;
}
@ -523,7 +526,8 @@ HttpTransactionChild::OnStopRequest(nsIRequest* aRequest, nsresult aStatus) {
MOZ_ASSERT(NS_FAILED(mStatus), "This shoule be only called when failure");
if (mDataBridgeParent) {
mDataBridgeParent->OnStopRequest(mStatus, ResourceTimingStructArgs(),
TimeStamp(), nsHttpHeaderArray());
TimeStamp(), nsHttpHeaderArray(),
TimeStamp::Now());
mDataBridgeParent = nullptr;
}
});
@ -554,7 +558,8 @@ HttpTransactionChild::OnStopRequest(nsIRequest* aRequest, nsresult aStatus) {
if (mDataBridgeParent) {
mDataBridgeParent->OnStopRequest(
aStatus, GetTimingAttributes(), lastActTabOpt,
responseTrailers ? *responseTrailers : nsHttpHeaderArray());
responseTrailers ? *responseTrailers : nsHttpHeaderArray(),
TimeStamp::Now());
mDataBridgeParent = nullptr;
}
@ -565,7 +570,7 @@ HttpTransactionChild::OnStopRequest(nsIRequest* aRequest, nsresult aStatus) {
mTransaction->GetTransferSize(),
ToTimingStructArgs(mTransaction->Timings()),
responseTrailers, mTransactionObserverResult,
lastActTabOpt, infoArgs);
lastActTabOpt, infoArgs, TimeStamp::Now());
return NS_OK;
}

View File

@ -414,20 +414,21 @@ mozilla::ipc::IPCResult HttpTransactionParent::RecvOnStartRequest(
const bool& aDataToChildProcess, const bool& aRestarted,
const uint32_t& aHTTPSSVCReceivedStage, const bool& aSupportsHttp3,
const nsIRequest::TRRMode& aMode, const TRRSkippedReason& aTrrSkipReason,
const uint32_t& aCaps) {
const uint32_t& aCaps, const TimeStamp& aOnStartRequestStartTime) {
mEventQ->RunOrEnqueue(new NeckoTargetChannelFunctionEvent(
this,
[self = UnsafePtr<HttpTransactionParent>(this), aStatus, aResponseHead,
securityInfo = nsCOMPtr{aSecurityInfo}, aProxyConnectFailed, aTimings,
aProxyConnectResponseCode,
aDataForSniffer = CopyableTArray{std::move(aDataForSniffer)},
aAltSvcUsed, aDataToChildProcess, aRestarted, aHTTPSSVCReceivedStage,
aSupportsHttp3, aMode, aTrrSkipReason, aCaps]() mutable {
this, [self = UnsafePtr<HttpTransactionParent>(this), aStatus,
aResponseHead, securityInfo = nsCOMPtr{aSecurityInfo},
aProxyConnectFailed, aTimings, aProxyConnectResponseCode,
aDataForSniffer = CopyableTArray{std::move(aDataForSniffer)},
aAltSvcUsed, aDataToChildProcess, aRestarted,
aHTTPSSVCReceivedStage, aSupportsHttp3, aMode, aTrrSkipReason,
aCaps, aOnStartRequestStartTime]() mutable {
self->DoOnStartRequest(
aStatus, aResponseHead, securityInfo, aProxyConnectFailed, aTimings,
aProxyConnectResponseCode, std::move(aDataForSniffer), aAltSvcUsed,
aDataToChildProcess, aRestarted, aHTTPSSVCReceivedStage,
aSupportsHttp3, aMode, aTrrSkipReason, aCaps);
aSupportsHttp3, aMode, aTrrSkipReason, aCaps,
aOnStartRequestStartTime);
}));
return IPC_OK();
}
@ -459,7 +460,7 @@ void HttpTransactionParent::DoOnStartRequest(
const bool& aDataToChildProcess, const bool& aRestarted,
const uint32_t& aHTTPSSVCReceivedStage, const bool& aSupportsHttp3,
const nsIRequest::TRRMode& aMode, const TRRSkippedReason& aSkipReason,
const uint32_t& aCaps) {
const uint32_t& aCaps, const TimeStamp& aOnStartRequestStartTime) {
LOG(("HttpTransactionParent::DoOnStartRequest [this=%p aStatus=%" PRIx32
"]\n",
this, static_cast<uint32_t>(aStatus)));
@ -478,6 +479,7 @@ void HttpTransactionParent::DoOnStartRequest(
mTRRSkipReason = aSkipReason;
mCaps = aCaps;
mSecurityInfo = aSecurityInfo;
mOnStartRequestStartTime = aOnStartRequestStartTime;
if (aResponseHead.isSome()) {
mResponseHead = MakeUnique<nsHttpResponseHead>(aResponseHead.ref());
@ -523,7 +525,8 @@ mozilla::ipc::IPCResult HttpTransactionParent::RecvOnTransportStatus(
}
mozilla::ipc::IPCResult HttpTransactionParent::RecvOnDataAvailable(
const nsCString& aData, const uint64_t& aOffset, const uint32_t& aCount) {
const nsCString& aData, const uint64_t& aOffset, const uint32_t& aCount,
const TimeStamp& aOnDataAvailableStartTime) {
LOG(("HttpTransactionParent::RecvOnDataAvailable [this=%p, aOffset= %" PRIu64
" aCount=%" PRIu32,
this, aOffset, aCount));
@ -541,14 +544,17 @@ mozilla::ipc::IPCResult HttpTransactionParent::RecvOnDataAvailable(
[self = UnsafePtr<HttpTransactionParent>(this)]() {
return self->GetODATarget();
},
[self = UnsafePtr<HttpTransactionParent>(this), aData, aOffset,
aCount]() { self->DoOnDataAvailable(aData, aOffset, aCount); }));
[self = UnsafePtr<HttpTransactionParent>(this), aData, aOffset, aCount,
aOnDataAvailableStartTime]() {
self->DoOnDataAvailable(aData, aOffset, aCount,
aOnDataAvailableStartTime);
}));
return IPC_OK();
}
void HttpTransactionParent::DoOnDataAvailable(const nsCString& aData,
const uint64_t& aOffset,
const uint32_t& aCount) {
void HttpTransactionParent::DoOnDataAvailable(
const nsCString& aData, const uint64_t& aOffset, const uint32_t& aCount,
const TimeStamp& aOnDataAvailableStartTime) {
LOG(("HttpTransactionParent::DoOnDataAvailable [this=%p]\n", this));
if (mCanceled) {
return;
@ -564,6 +570,7 @@ void HttpTransactionParent::DoOnDataAvailable(const nsCString& aData,
return;
}
mOnDataAvailableStartTime = aOnDataAvailableStartTime;
AutoEventEnqueuer ensureSerialDispatch(mEventQ);
rv = mChannel->OnDataAvailable(this, stringStream, aOffset, aCount);
if (NS_FAILED(rv)) {
@ -597,7 +604,8 @@ mozilla::ipc::IPCResult HttpTransactionParent::RecvOnStopRequest(
const Maybe<nsHttpHeaderArray>& aResponseTrailers,
Maybe<TransactionObserverResult>&& aTransactionObserverResult,
const TimeStamp& aLastActiveTabOptHit,
const HttpConnectionInfoCloneArgs& aArgs) {
const HttpConnectionInfoCloneArgs& aArgs,
const TimeStamp& aOnStopRequestStartTime) {
LOG(("HttpTransactionParent::RecvOnStopRequest [this=%p status=%" PRIx32
"]\n",
this, static_cast<uint32_t>(aStatus)));
@ -613,10 +621,11 @@ mozilla::ipc::IPCResult HttpTransactionParent::RecvOnStopRequest(
this, [self = UnsafePtr<HttpTransactionParent>(this), aStatus,
aResponseIsComplete, aTransferSize, aTimings, aResponseTrailers,
aTransactionObserverResult{std::move(aTransactionObserverResult)},
cinfo{std::move(cinfo)}]() mutable {
cinfo{std::move(cinfo)}, aOnStopRequestStartTime]() mutable {
self->DoOnStopRequest(aStatus, aResponseIsComplete, aTransferSize,
aTimings, aResponseTrailers,
std::move(aTransactionObserverResult), cinfo);
std::move(aTransactionObserverResult), cinfo,
aOnStopRequestStartTime);
}));
return IPC_OK();
}
@ -626,7 +635,7 @@ void HttpTransactionParent::DoOnStopRequest(
const int64_t& aTransferSize, const TimingStructArgs& aTimings,
const Maybe<nsHttpHeaderArray>& aResponseTrailers,
Maybe<TransactionObserverResult>&& aTransactionObserverResult,
nsHttpConnectionInfo* aConnInfo) {
nsHttpConnectionInfo* aConnInfo, const TimeStamp& aOnStopRequestStartTime) {
LOG(("HttpTransactionParent::DoOnStopRequest [this=%p]\n", this));
if (mCanceled) {
return;
@ -640,6 +649,7 @@ void HttpTransactionParent::DoOnStopRequest(
mResponseIsComplete = aResponseIsComplete;
mTransferSize = aTransferSize;
mOnStopRequestStartTime = aOnStopRequestStartTime;
TimingStructArgsToTimingsStruct(aTimings, mTimings);

View File

@ -56,21 +56,22 @@ class HttpTransactionParent final : public PHttpTransactionParent,
const bool& aDataToChildProcess, const bool& aRestarted,
const uint32_t& aHTTPSSVCReceivedStage, const bool& aSupportsHttp3,
const nsIRequest::TRRMode& aMode, const TRRSkippedReason& aSkipReason,
const uint32_t& aCaps);
const uint32_t& aCaps, const TimeStamp& aOnStartRequestStartTime);
mozilla::ipc::IPCResult RecvOnTransportStatus(
const nsresult& aStatus, const int64_t& aProgress,
const int64_t& aProgressMax,
Maybe<NetworkAddressArg>&& aNetworkAddressArg);
mozilla::ipc::IPCResult RecvOnDataAvailable(const nsCString& aData,
const uint64_t& aOffset,
const uint32_t& aCount);
mozilla::ipc::IPCResult RecvOnDataAvailable(
const nsCString& aData, const uint64_t& aOffset, const uint32_t& aCount,
const TimeStamp& aOnDataAvailableStartTime);
mozilla::ipc::IPCResult RecvOnStopRequest(
const nsresult& aStatus, const bool& aResponseIsComplete,
const int64_t& aTransferSize, const TimingStructArgs& aTimings,
const Maybe<nsHttpHeaderArray>& responseTrailers,
Maybe<TransactionObserverResult>&& aTransactionObserverResult,
const TimeStamp& aLastActiveTabOptHit,
const HttpConnectionInfoCloneArgs& aArgs);
const HttpConnectionInfoCloneArgs& aArgs,
const TimeStamp& aOnStopRequestStartTime);
mozilla::ipc::IPCResult RecvOnInitFailed(const nsresult& aStatus);
mozilla::ipc::IPCResult RecvOnH2PushStream(const uint32_t& aPushedStreamId,
@ -93,6 +94,16 @@ class HttpTransactionParent final : public PHttpTransactionParent,
mRedirectEnd = aRedirectEnd;
}
virtual TimeStamp GetOnStartRequestStartTime() const override {
return mOnStartRequestStartTime;
}
virtual TimeStamp GetDataAvailableStartTime() const override {
return mOnDataAvailableStartTime;
}
virtual TimeStamp GetOnStopRequestStartTime() const override {
return mOnStopRequestStartTime;
}
private:
virtual ~HttpTransactionParent();
@ -107,15 +118,17 @@ class HttpTransactionParent final : public PHttpTransactionParent,
const bool& aDataToChildProcess, const bool& aRestarted,
const uint32_t& aHTTPSSVCReceivedStage, const bool& aSupportsHttp3,
const nsIRequest::TRRMode& aMode, const TRRSkippedReason& aSkipReason,
const uint32_t& aCaps);
const uint32_t& aCaps, const TimeStamp& aOnStartRequestStartTime);
void DoOnDataAvailable(const nsCString& aData, const uint64_t& aOffset,
const uint32_t& aCount);
const uint32_t& aCount,
const TimeStamp& aOnDataAvailableStartTime);
void DoOnStopRequest(
const nsresult& aStatus, const bool& aResponseIsComplete,
const int64_t& aTransferSize, const TimingStructArgs& aTimings,
const Maybe<nsHttpHeaderArray>& responseTrailers,
Maybe<TransactionObserverResult>&& aTransactionObserverResult,
nsHttpConnectionInfo* aConnInfo);
nsHttpConnectionInfo* aConnInfo,
const TimeStamp& aOnStopRequestStartTime);
void DoNotifyListener();
void ContinueDoNotifyListener();
// Get event target for ODA.
@ -164,6 +177,9 @@ class HttpTransactionParent final : public PHttpTransactionParent,
TimingStruct mTimings;
TimeStamp mDomainLookupStart;
TimeStamp mDomainLookupEnd;
TimeStamp mOnStartRequestStartTime;
TimeStamp mOnDataAvailableStartTime;
TimeStamp mOnStopRequestStartTime;
TransactionObserverFunc mTransactionObserver;
OnPushCallback mOnPushCallback;
nsTArray<uint8_t> mDataForSniffer;

View File

@ -169,6 +169,10 @@ class HttpTransactionShell : public nsISupports {
virtual bool GetSupportsHTTP3() = 0;
virtual void SetIsForWebTransport(bool aIsForWebTransport) = 0;
virtual TimeStamp GetOnStartRequestStartTime() const { return TimeStamp(); }
virtual TimeStamp GetDataAvailableStartTime() const { return TimeStamp(); }
virtual TimeStamp GetOnStopRequestStartTime() const { return TimeStamp(); }
};
NS_DEFINE_STATIC_IID_ACCESSOR(HttpTransactionShell, HTTPTRANSACTIONSHELL_IID)

View File

@ -14,12 +14,14 @@ async protocol PBackgroundDataBridge
child:
async OnTransportAndData(uint64_t offset,
uint32_t count,
nsCString data);
nsCString data,
TimeStamp onDataAvailableStart);
async OnStopRequest(nsresult aStatus,
ResourceTimingStructArgs timing,
TimeStamp lastActiveTabOptimization,
nsHttpHeaderArray responseTrailers);
nsHttpHeaderArray responseTrailers,
TimeStamp onStopRequestStart);
both:
async __delete__();

View File

@ -26,7 +26,8 @@ child:
bool useResponseHead,
nsHttpHeaderArray requestHeaders,
HttpChannelOnStartRequestArgs args,
HttpChannelAltDataStream altData);
HttpChannelAltDataStream altData,
TimeStamp onStartRequestStart);
// Combines a single OnDataAvailable and its associated OnProgress &
// OnStatus calls into one IPDL message
@ -35,7 +36,8 @@ child:
uint64_t offset,
uint32_t count,
nsCString data,
bool dataFromSocketProcess);
bool dataFromSocketProcess,
TimeStamp onDataAvailableStart);
async OnStopRequest(nsresult channelStatus,
@ -43,7 +45,8 @@ child:
TimeStamp lastActiveTabOptimization,
nsHttpHeaderArray responseTrailers,
ConsoleReportCollected[] consoleReport,
bool fromSocketProcess);
bool fromSocketProcess,
TimeStamp onStopRequestStart);
async OnConsoleReport(ConsoleReportCollected[] consoleReport);

View File

@ -59,14 +59,16 @@ parent:
bool supportsHttp3,
TRRMode trrMode,
TRRSkippedReason trrSkipReason,
uint32_t caps);
uint32_t caps,
TimeStamp onStartRequestStart);
async OnTransportStatus(nsresult status,
int64_t progress,
int64_t progressMax,
NetworkAddressArg? networkAddressArg);
async OnDataAvailable(nsCString data,
uint64_t offset,
uint32_t count);
uint32_t count,
TimeStamp onDataAvailableStart);
async OnStopRequest(nsresult status,
bool responseIsComplete,
int64_t transferSize,
@ -74,7 +76,8 @@ parent:
nsHttpHeaderArray? responseTrailers,
TransactionObserverResult? transactionObserverResult,
TimeStamp lastActiveTabOptimization,
HttpConnectionInfoCloneArgs connInfoArgs);
HttpConnectionInfoCloneArgs connInfoArgs,
TimeStamp onStopRequestStart);
async OnInitFailed(nsresult status);
async OnH2PushStream(uint32_t pushedStreamId,
nsCString resourceUrl,

View File

@ -62,6 +62,7 @@
#include "mozilla/Attributes.h"
#include "mozilla/BasePrincipal.h"
#include "mozilla/DebugOnly.h"
#include "mozilla/PerfStats.h"
#include "mozilla/Preferences.h"
#include "mozilla/ProfilerLabels.h"
#include "mozilla/Components.h"
@ -7117,16 +7118,15 @@ nsHttpChannel::GetRequestMethod(nsACString& aMethod) {
// nsHttpChannel::nsIRequestObserver
//-----------------------------------------------------------------------------
static void RecordOnStartTelemetry(nsresult aStatus,
HttpTransactionShell* aTransaction,
bool aIsNavigation) {
void nsHttpChannel::RecordOnStartTelemetry(nsresult aStatus,
bool aIsNavigation) {
Telemetry::Accumulate(Telemetry::HTTP_CHANNEL_ONSTART_SUCCESS,
NS_SUCCEEDED(aStatus));
if (aTransaction) {
if (mTransaction) {
Telemetry::Accumulate(
Telemetry::HTTP3_CHANNEL_ONSTART_SUCCESS,
(aTransaction->IsHttp3Used()) ? "http3"_ns : "no_http3"_ns,
(mTransaction->IsHttp3Used()) ? "http3"_ns : "no_http3"_ns,
NS_SUCCEEDED(aStatus));
}
@ -7157,6 +7157,24 @@ static void RecordOnStartTelemetry(nsresult aStatus,
static_cast<uint32_t>(state));
}
}
if (nsIOService::UseSocketProcess() && mTransaction) {
const TimeStamp now = TimeStamp::Now();
TimeStamp responseEnd = mTransaction->GetResponseEnd();
if (!responseEnd.IsNull()) {
PerfStats::RecordMeasurement(PerfStats::Metric::ResponseEndSocketToParent,
now - responseEnd);
}
mOnStartRequestStartTime = mTransaction->GetOnStartRequestStartTime();
if (!mOnStartRequestStartTime.IsNull()) {
PerfStats::RecordMeasurement(
PerfStats::Metric::OnStartRequestSocketToParent,
now - mOnStartRequestStartTime);
}
} else {
mOnStartRequestStartTime = TimeStamp::Now();
}
}
NS_IMETHODIMP
@ -7191,7 +7209,7 @@ nsHttpChannel::OnStartRequest(nsIRequest* request) {
"]\n",
this, request, static_cast<uint32_t>(static_cast<nsresult>(mStatus))));
RecordOnStartTelemetry(mStatus, mTransaction, IsNavigation());
RecordOnStartTelemetry(mStatus, IsNavigation());
if (mRaceCacheWithNetwork) {
LOG(
@ -7734,6 +7752,17 @@ nsHttpChannel::OnStopRequest(nsIRequest* request, nsresult status) {
mResponseTrailers = mTransaction->TakeResponseTrailers();
if (nsIOService::UseSocketProcess() && mTransaction) {
mOnStopRequestStartTime = mTransaction->GetOnStopRequestStartTime();
if (!mOnStopRequestStartTime.IsNull()) {
PerfStats::RecordMeasurement(
PerfStats::Metric::OnStopRequestSocketToParent,
TimeStamp::Now() - mOnStopRequestStartTime);
}
} else {
mOnStopRequestStartTime = TimeStamp::Now();
}
// at this point, we're done with the transaction
mTransactionTimings = mTransaction->Timings();
mTransaction = nullptr;
@ -8258,6 +8287,16 @@ nsHttpChannel::OnDataAvailable(nsIRequest* request, nsIInputStream* input,
seekable = nullptr;
}
if (nsIOService::UseSocketProcess() && mTransaction) {
mOnDataAvailableStartTime = mTransaction->GetDataAvailableStartTime();
if (!mOnDataAvailableStartTime.IsNull()) {
PerfStats::RecordMeasurement(
PerfStats::Metric::OnDataAvailableSocketToParent,
TimeStamp::Now() - mOnDataAvailableStartTime);
}
} else {
mOnDataAvailableStartTime = TimeStamp::Now();
}
nsresult rv =
mListener->OnDataAvailable(this, input, mLogicalOffset, count);
if (NS_SUCCEEDED(rv)) {

View File

@ -802,6 +802,8 @@ class nsHttpChannel final : public HttpBaseChannel,
void SetHTTPSSVCRecord(already_AddRefed<nsIDNSHTTPSSVCRecord>&& aRecord);
void RecordOnStartTelemetry(nsresult aStatus, bool aIsNavigation);
// Timer used to delay the network request, or to trigger the network
// request if retrieving the cache entry takes too long.
nsCOMPtr<nsITimer> mNetworkTriggerTimer;

View File

@ -47,6 +47,13 @@
MACRO(HttpChannelAsyncOpenToTransactionPending) \
MACRO(HttpChannelResponseStartParentToContent) \
MACRO(HttpChannelResponseEndParentToContent) \
MACRO(ResponseEndSocketToParent) \
MACRO(OnStartRequestSocketToParent) \
MACRO(OnDataAvailableSocketToParent) \
MACRO(OnStopRequestSocketToParent) \
MACRO(OnStartRequestToContent) \
MACRO(OnDataAvailableToContent) \
MACRO(OnStopRequestToContent) \
MACRO(JSBC_Compression) \
MACRO(JSBC_Decompression) \
MACRO(JSBC_IO_Read) \