1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/netwerk/protocol/http/ConnectionDiagnostics.cpp Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,290 @@
1.4 +/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
1.5 +/* vim: set sw=2 ts=8 et tw=80 : */
1.6 +/* This Source Code Form is subject to the terms of the Mozilla Public
1.7 + * License, v. 2.0. If a copy of the MPL was not distributed with this
1.8 + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
1.9 +
1.10 +// HttpLog.h should generally be included first
1.11 +#include "HttpLog.h"
1.12 +
1.13 +#include "nsHttpConnectionMgr.h"
1.14 +#include "nsHttpConnection.h"
1.15 +#include "SpdySession3.h"
1.16 +#include "SpdySession31.h"
1.17 +#include "Http2Session.h"
1.18 +#include "nsHttpHandler.h"
1.19 +#include "nsIConsoleService.h"
1.20 +#include "nsHttpRequestHead.h"
1.21 +
1.22 +extern PRThread *gSocketThread;
1.23 +
1.24 +namespace mozilla {
1.25 +namespace net {
1.26 +
1.27 +void
1.28 +nsHttpConnectionMgr::PrintDiagnostics()
1.29 +{
1.30 + PostEvent(&nsHttpConnectionMgr::OnMsgPrintDiagnostics, 0, nullptr);
1.31 +}
1.32 +
1.33 +void
1.34 +nsHttpConnectionMgr::OnMsgPrintDiagnostics(int32_t, void *)
1.35 +{
1.36 + MOZ_ASSERT(PR_GetCurrentThread() == gSocketThread);
1.37 +
1.38 + nsCOMPtr<nsIConsoleService> consoleService =
1.39 + do_GetService(NS_CONSOLESERVICE_CONTRACTID);
1.40 + if (!consoleService)
1.41 + return;
1.42 +
1.43 + mLogData.AppendPrintf("HTTP Connection Diagnostics\n---------------------\n");
1.44 + mLogData.AppendPrintf("IsSpdyEnabled() = %d\n", gHttpHandler->IsSpdyEnabled());
1.45 + mLogData.AppendPrintf("MaxSocketCount() = %d\n", gHttpHandler->MaxSocketCount());
1.46 + mLogData.AppendPrintf("mNumActiveConns = %d\n", mNumActiveConns);
1.47 + mLogData.AppendPrintf("mNumIdleConns = %d\n", mNumIdleConns);
1.48 +
1.49 + mCT.Enumerate(PrintDiagnosticsCB, this);
1.50 +
1.51 + consoleService->LogStringMessage(NS_ConvertUTF8toUTF16(mLogData).Data());
1.52 + mLogData.Truncate();
1.53 +}
1.54 +
1.55 +PLDHashOperator
1.56 +nsHttpConnectionMgr::PrintDiagnosticsCB(const nsACString &key,
1.57 + nsAutoPtr<nsConnectionEntry> &ent,
1.58 + void *closure)
1.59 +{
1.60 + nsHttpConnectionMgr *self = static_cast<nsHttpConnectionMgr *>(closure);
1.61 + uint32_t i;
1.62 +
1.63 + self->mLogData.AppendPrintf(" ent host = %s hashkey = %s\n",
1.64 + ent->mConnInfo->Host(), ent->mConnInfo->HashKey().get());
1.65 + self->mLogData.AppendPrintf(" AtActiveConnectionLimit = %d\n",
1.66 + self->AtActiveConnectionLimit(ent, NS_HTTP_ALLOW_KEEPALIVE));
1.67 + self->mLogData.AppendPrintf(" RestrictConnections = %d\n",
1.68 + self->RestrictConnections(ent));
1.69 + self->mLogData.AppendPrintf(" Pending Q Length = %u\n",
1.70 + ent->mPendingQ.Length());
1.71 + self->mLogData.AppendPrintf(" Active Conns Length = %u\n",
1.72 + ent->mActiveConns.Length());
1.73 + self->mLogData.AppendPrintf(" Idle Conns Length = %u\n",
1.74 + ent->mIdleConns.Length());
1.75 + self->mLogData.AppendPrintf(" Half Opens Length = %u\n",
1.76 + ent->mHalfOpens.Length());
1.77 + self->mLogData.AppendPrintf(" Coalescing Key = %s\n",
1.78 + ent->mCoalescingKey.get());
1.79 + self->mLogData.AppendPrintf(" Spdy using = %d, tested = %d, preferred = %d\n",
1.80 + ent->mUsingSpdy, ent->mTestedSpdy, ent->mSpdyPreferred);
1.81 + self->mLogData.AppendPrintf(" pipelinestate = %d penalty = %d\n",
1.82 + ent->mPipelineState, ent->mPipeliningPenalty);
1.83 + for (i = 0; i < nsAHttpTransaction::CLASS_MAX; ++i) {
1.84 + self->mLogData.AppendPrintf(" pipeline per class penalty 0x%x %d\n",
1.85 + i, ent->mPipeliningClassPenalty[i]);
1.86 + }
1.87 + for (i = 0; i < ent->mActiveConns.Length(); ++i) {
1.88 + self->mLogData.AppendPrintf(" :: Active Connection #%u\n", i);
1.89 + ent->mActiveConns[i]->PrintDiagnostics(self->mLogData);
1.90 + }
1.91 + for (i = 0; i < ent->mIdleConns.Length(); ++i) {
1.92 + self->mLogData.AppendPrintf(" :: Idle Connection #%u\n", i);
1.93 + ent->mIdleConns[i]->PrintDiagnostics(self->mLogData);
1.94 + }
1.95 + for (i = 0; i < ent->mHalfOpens.Length(); ++i) {
1.96 + self->mLogData.AppendPrintf(" :: Half Open #%u\n", i);
1.97 + ent->mHalfOpens[i]->PrintDiagnostics(self->mLogData);
1.98 + }
1.99 + for (i = 0; i < ent->mPendingQ.Length(); ++i) {
1.100 + self->mLogData.AppendPrintf(" :: Pending Transaction #%u\n", i);
1.101 + ent->mPendingQ[i]->PrintDiagnostics(self->mLogData);
1.102 + }
1.103 +
1.104 + return PL_DHASH_NEXT;
1.105 +}
1.106 +
1.107 +void
1.108 +nsHttpConnectionMgr::nsHalfOpenSocket::PrintDiagnostics(nsCString &log)
1.109 +{
1.110 + log.AppendPrintf(" has connected = %d, isSpeculative = %d\n",
1.111 + HasConnected(), IsSpeculative());
1.112 +
1.113 + TimeStamp now = TimeStamp::Now();
1.114 +
1.115 + if (mPrimarySynStarted.IsNull())
1.116 + log.AppendPrintf(" primary not started\n");
1.117 + else
1.118 + log.AppendPrintf(" primary started %.2fms ago\n",
1.119 + (now - mPrimarySynStarted).ToMilliseconds());
1.120 +
1.121 + if (mBackupSynStarted.IsNull())
1.122 + log.AppendPrintf(" backup not started\n");
1.123 + else
1.124 + log.AppendPrintf(" backup started %.2f ago\n",
1.125 + (now - mBackupSynStarted).ToMilliseconds());
1.126 +
1.127 + log.AppendPrintf(" primary transport %d, backup transport %d\n",
1.128 + !!mSocketTransport.get(), !!mBackupTransport.get());
1.129 +}
1.130 +
1.131 +void
1.132 +nsHttpConnection::PrintDiagnostics(nsCString &log)
1.133 +{
1.134 + log.AppendPrintf(" CanDirectlyActivate = %d\n", CanDirectlyActivate());
1.135 +
1.136 + log.AppendPrintf(" npncomplete = %d setupSSLCalled = %d\n",
1.137 + mNPNComplete, mSetupSSLCalled);
1.138 +
1.139 + log.AppendPrintf(" spdyVersion = %d reportedSpdy = %d everspdy = %d\n",
1.140 + mUsingSpdyVersion, mReportedSpdy, mEverUsedSpdy);
1.141 +
1.142 + log.AppendPrintf(" iskeepalive = %d dontReuse = %d isReused = %d\n",
1.143 + IsKeepAlive(), mDontReuse, mIsReused);
1.144 +
1.145 + log.AppendPrintf(" mTransaction = %d mSpdySession = %d\n",
1.146 + !!mTransaction.get(), !!mSpdySession.get());
1.147 +
1.148 + PRIntervalTime now = PR_IntervalNow();
1.149 + log.AppendPrintf(" time since last read = %ums\n",
1.150 + PR_IntervalToMilliseconds(now - mLastReadTime));
1.151 +
1.152 + log.AppendPrintf(" max-read/read/written %lld/%lld/%lld\n",
1.153 + mMaxBytesRead, mTotalBytesRead, mTotalBytesWritten);
1.154 +
1.155 + log.AppendPrintf(" rtt = %ums\n", PR_IntervalToMilliseconds(mRtt));
1.156 +
1.157 + log.AppendPrintf(" idlemonitoring = %d transactionCount=%d\n",
1.158 + mIdleMonitoring, mHttp1xTransactionCount);
1.159 +
1.160 + log.AppendPrintf(" supports pipeline = %d classification = 0x%x\n",
1.161 + mSupportsPipelining, mClassification);
1.162 +
1.163 + if (mSpdySession)
1.164 + mSpdySession->PrintDiagnostics(log);
1.165 +}
1.166 +
1.167 +
1.168 +void
1.169 +SpdySession3::PrintDiagnostics(nsCString &log)
1.170 +{
1.171 + log.AppendPrintf(" ::: SPDY VERSION 3\n");
1.172 + log.AppendPrintf(" shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
1.173 + mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
1.174 +
1.175 + log.AppendPrintf(" concurrent = %d maxconcurrent = %d\n",
1.176 + mConcurrent, mMaxConcurrent);
1.177 +
1.178 + log.AppendPrintf(" roomformorestreams = %d roomformoreconcurrent = %d\n",
1.179 + RoomForMoreStreams(), RoomForMoreConcurrent());
1.180 +
1.181 + log.AppendPrintf(" transactionHashCount = %d streamIDHashCount = %d\n",
1.182 + mStreamTransactionHash.Count(),
1.183 + mStreamIDHash.Count());
1.184 +
1.185 + log.AppendPrintf(" Queued Stream Size = %d\n", mQueuedStreams.GetSize());
1.186 +
1.187 + PRIntervalTime now = PR_IntervalNow();
1.188 + log.AppendPrintf(" Ping Threshold = %ums next ping id = 0x%X\n",
1.189 + PR_IntervalToMilliseconds(mPingThreshold),
1.190 + mNextPingID);
1.191 + log.AppendPrintf(" Ping Timeout = %ums\n",
1.192 + PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
1.193 + log.AppendPrintf(" Idle for Any Activity (ping) = %ums\n",
1.194 + PR_IntervalToMilliseconds(now - mLastReadEpoch));
1.195 + log.AppendPrintf(" Idle for Data Activity = %ums\n",
1.196 + PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
1.197 + if (mPingSentEpoch)
1.198 + log.AppendPrintf(" Ping Outstanding (ping) = %ums, expired = %d\n",
1.199 + PR_IntervalToMilliseconds(now - mPingSentEpoch),
1.200 + now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
1.201 + else
1.202 + log.AppendPrintf(" No Ping Outstanding\n");
1.203 +}
1.204 +
1.205 +void
1.206 +SpdySession31::PrintDiagnostics(nsCString &log)
1.207 +{
1.208 + log.AppendPrintf(" ::: SPDY VERSION 3.1\n");
1.209 + log.AppendPrintf(" shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
1.210 + mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
1.211 +
1.212 + log.AppendPrintf(" concurrent = %d maxconcurrent = %d\n",
1.213 + mConcurrent, mMaxConcurrent);
1.214 +
1.215 + log.AppendPrintf(" roomformorestreams = %d roomformoreconcurrent = %d\n",
1.216 + RoomForMoreStreams(), RoomForMoreConcurrent());
1.217 +
1.218 + log.AppendPrintf(" transactionHashCount = %d streamIDHashCount = %d\n",
1.219 + mStreamTransactionHash.Count(),
1.220 + mStreamIDHash.Count());
1.221 +
1.222 + log.AppendPrintf(" Queued Stream Size = %d\n", mQueuedStreams.GetSize());
1.223 +
1.224 + PRIntervalTime now = PR_IntervalNow();
1.225 + log.AppendPrintf(" Ping Threshold = %ums next ping id = 0x%X\n",
1.226 + PR_IntervalToMilliseconds(mPingThreshold),
1.227 + mNextPingID);
1.228 + log.AppendPrintf(" Ping Timeout = %ums\n",
1.229 + PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
1.230 + log.AppendPrintf(" Idle for Any Activity (ping) = %ums\n",
1.231 + PR_IntervalToMilliseconds(now - mLastReadEpoch));
1.232 + log.AppendPrintf(" Idle for Data Activity = %ums\n",
1.233 + PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
1.234 + if (mPingSentEpoch)
1.235 + log.AppendPrintf(" Ping Outstanding (ping) = %ums, expired = %d\n",
1.236 + PR_IntervalToMilliseconds(now - mPingSentEpoch),
1.237 + now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
1.238 + else
1.239 + log.AppendPrintf(" No Ping Outstanding\n");
1.240 +}
1.241 +
1.242 +void
1.243 +Http2Session::PrintDiagnostics(nsCString &log)
1.244 +{
1.245 + log.AppendPrintf(" ::: HTTP2\n");
1.246 + log.AppendPrintf(" shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
1.247 + mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
1.248 +
1.249 + log.AppendPrintf(" concurrent = %d maxconcurrent = %d\n",
1.250 + mConcurrent, mMaxConcurrent);
1.251 +
1.252 + log.AppendPrintf(" roomformorestreams = %d roomformoreconcurrent = %d\n",
1.253 + RoomForMoreStreams(), RoomForMoreConcurrent());
1.254 +
1.255 + log.AppendPrintf(" transactionHashCount = %d streamIDHashCount = %d\n",
1.256 + mStreamTransactionHash.Count(),
1.257 + mStreamIDHash.Count());
1.258 +
1.259 + log.AppendPrintf(" Queued Stream Size = %d\n", mQueuedStreams.GetSize());
1.260 +
1.261 + PRIntervalTime now = PR_IntervalNow();
1.262 + log.AppendPrintf(" Ping Threshold = %ums\n",
1.263 + PR_IntervalToMilliseconds(mPingThreshold));
1.264 + log.AppendPrintf(" Ping Timeout = %ums\n",
1.265 + PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
1.266 + log.AppendPrintf(" Idle for Any Activity (ping) = %ums\n",
1.267 + PR_IntervalToMilliseconds(now - mLastReadEpoch));
1.268 + log.AppendPrintf(" Idle for Data Activity = %ums\n",
1.269 + PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
1.270 + if (mPingSentEpoch)
1.271 + log.AppendPrintf(" Ping Outstanding (ping) = %ums, expired = %d\n",
1.272 + PR_IntervalToMilliseconds(now - mPingSentEpoch),
1.273 + now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
1.274 + else
1.275 + log.AppendPrintf(" No Ping Outstanding\n");
1.276 +}
1.277 +
1.278 +void
1.279 +nsHttpTransaction::PrintDiagnostics(nsCString &log)
1.280 +{
1.281 + if (!mRequestHead)
1.282 + return;
1.283 +
1.284 + log.AppendPrintf(" ::: uri = %s\n",
1.285 + nsAutoCString(mRequestHead->RequestURI()).get());
1.286 + log.AppendPrintf(" caps = 0x%x\n", mCaps);
1.287 + log.AppendPrintf(" priority = %d\n", mPriority);
1.288 + log.AppendPrintf(" restart count = %u\n", mRestartCount);
1.289 + log.AppendPrintf(" classification = 0x%x\n", mClassification);
1.290 +}
1.291 +
1.292 +} // namespace mozilla::net
1.293 +} // namespace mozilla
