michael@0: /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
michael@0: /* vim: set sw=2 ts=8 et tw=80 : */
michael@0: /* This Source Code Form is subject to the terms of the Mozilla Public
michael@0:  * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0:  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0: 
michael@0: // HttpLog.h should generally be included first
michael@0: #include "HttpLog.h"
michael@0: 
michael@0: #include "nsHttpConnectionMgr.h"
michael@0: #include "nsHttpConnection.h"
michael@0: #include "SpdySession3.h"
michael@0: #include "SpdySession31.h"
michael@0: #include "Http2Session.h"
michael@0: #include "nsHttpHandler.h"
michael@0: #include "nsIConsoleService.h"
michael@0: #include "nsHttpRequestHead.h"
michael@0: 
michael@0: extern PRThread *gSocketThread;
michael@0: 
michael@0: namespace mozilla {
michael@0: namespace net {
michael@0: 
michael@0: void
michael@0: nsHttpConnectionMgr::PrintDiagnostics()
michael@0: {
michael@0:   PostEvent(&nsHttpConnectionMgr::OnMsgPrintDiagnostics, 0, nullptr);
michael@0: }
michael@0: 
michael@0: void
michael@0: nsHttpConnectionMgr::OnMsgPrintDiagnostics(int32_t, void *)
michael@0: {
michael@0:   MOZ_ASSERT(PR_GetCurrentThread() == gSocketThread);
michael@0: 
michael@0:   nsCOMPtr<nsIConsoleService> consoleService =
michael@0:     do_GetService(NS_CONSOLESERVICE_CONTRACTID);
michael@0:   if (!consoleService)
michael@0:     return;
michael@0: 
michael@0:   mLogData.AppendPrintf("HTTP Connection Diagnostics\n---------------------\n");
michael@0:   mLogData.AppendPrintf("IsSpdyEnabled() = %d\n", gHttpHandler->IsSpdyEnabled());
michael@0:   mLogData.AppendPrintf("MaxSocketCount() = %d\n", gHttpHandler->MaxSocketCount());
michael@0:   mLogData.AppendPrintf("mNumActiveConns = %d\n", mNumActiveConns);
michael@0:   mLogData.AppendPrintf("mNumIdleConns = %d\n", mNumIdleConns);
michael@0: 
michael@0:   mCT.Enumerate(PrintDiagnosticsCB, this);
michael@0: 
michael@0:   consoleService->LogStringMessage(NS_ConvertUTF8toUTF16(mLogData).Data());
michael@0:   mLogData.Truncate();
michael@0: }
michael@0: 
michael@0: PLDHashOperator
michael@0: nsHttpConnectionMgr::PrintDiagnosticsCB(const nsACString &key,
michael@0:                                         nsAutoPtr<nsConnectionEntry> &ent,
michael@0:                                         void *closure)
michael@0: {
michael@0:   nsHttpConnectionMgr *self = static_cast<nsHttpConnectionMgr *>(closure);
michael@0:   uint32_t i;
michael@0: 
michael@0:   self->mLogData.AppendPrintf(" ent host = %s hashkey = %s\n",
michael@0:                               ent->mConnInfo->Host(), ent->mConnInfo->HashKey().get());
michael@0:   self->mLogData.AppendPrintf("   AtActiveConnectionLimit = %d\n",
michael@0:                               self->AtActiveConnectionLimit(ent, NS_HTTP_ALLOW_KEEPALIVE));
michael@0:   self->mLogData.AppendPrintf("   RestrictConnections = %d\n",
michael@0:                               self->RestrictConnections(ent));
michael@0:   self->mLogData.AppendPrintf("   Pending Q Length = %u\n",
michael@0:                               ent->mPendingQ.Length());
michael@0:   self->mLogData.AppendPrintf("   Active Conns Length = %u\n",
michael@0:                               ent->mActiveConns.Length());
michael@0:   self->mLogData.AppendPrintf("   Idle Conns Length = %u\n",
michael@0:                               ent->mIdleConns.Length());
michael@0:   self->mLogData.AppendPrintf("   Half Opens Length = %u\n",
michael@0:                               ent->mHalfOpens.Length());
michael@0:   self->mLogData.AppendPrintf("   Coalescing Key = %s\n",
michael@0:                               ent->mCoalescingKey.get());
michael@0:   self->mLogData.AppendPrintf("   Spdy using = %d, tested = %d, preferred = %d\n",
michael@0:                               ent->mUsingSpdy, ent->mTestedSpdy, ent->mSpdyPreferred);
michael@0:   self->mLogData.AppendPrintf("   pipelinestate = %d penalty = %d\n",
michael@0:                               ent->mPipelineState, ent->mPipeliningPenalty);
michael@0:   for (i = 0; i < nsAHttpTransaction::CLASS_MAX; ++i) {
michael@0:     self->mLogData.AppendPrintf("   pipeline per class penalty 0x%x %d\n",
michael@0:                                 i, ent->mPipeliningClassPenalty[i]);
michael@0:   }
michael@0:   for (i = 0; i < ent->mActiveConns.Length(); ++i) {
michael@0:     self->mLogData.AppendPrintf("   :: Active Connection #%u\n", i);
michael@0:     ent->mActiveConns[i]->PrintDiagnostics(self->mLogData);
michael@0:   }
michael@0:   for (i = 0; i < ent->mIdleConns.Length(); ++i) {
michael@0:     self->mLogData.AppendPrintf("   :: Idle Connection #%u\n", i);
michael@0:     ent->mIdleConns[i]->PrintDiagnostics(self->mLogData);
michael@0:   }
michael@0:   for (i = 0; i < ent->mHalfOpens.Length(); ++i) {
michael@0:     self->mLogData.AppendPrintf("   :: Half Open #%u\n", i);
michael@0:     ent->mHalfOpens[i]->PrintDiagnostics(self->mLogData);
michael@0:   }
michael@0:   for (i = 0; i < ent->mPendingQ.Length(); ++i) {
michael@0:     self->mLogData.AppendPrintf("   :: Pending Transaction #%u\n", i);
michael@0:     ent->mPendingQ[i]->PrintDiagnostics(self->mLogData);
michael@0:   }
michael@0: 
michael@0:   return PL_DHASH_NEXT;
michael@0: }
michael@0: 
michael@0: void
michael@0: nsHttpConnectionMgr::nsHalfOpenSocket::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   log.AppendPrintf("     has connected = %d, isSpeculative = %d\n",
michael@0:                    HasConnected(), IsSpeculative());
michael@0: 
michael@0:   TimeStamp now = TimeStamp::Now();
michael@0: 
michael@0:   if (mPrimarySynStarted.IsNull())
michael@0:     log.AppendPrintf("    primary not started\n");
michael@0:   else
michael@0:     log.AppendPrintf("    primary started %.2fms ago\n",
michael@0:                      (now - mPrimarySynStarted).ToMilliseconds());
michael@0: 
michael@0:   if (mBackupSynStarted.IsNull())
michael@0:     log.AppendPrintf("    backup not started\n");
michael@0:   else
michael@0:     log.AppendPrintf("    backup started %.2f ago\n",
michael@0:                      (now - mBackupSynStarted).ToMilliseconds());
michael@0: 
michael@0:   log.AppendPrintf("    primary transport %d, backup transport %d\n",
michael@0:                    !!mSocketTransport.get(), !!mBackupTransport.get());
michael@0: }
michael@0: 
michael@0: void
michael@0: nsHttpConnection::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   log.AppendPrintf("    CanDirectlyActivate = %d\n", CanDirectlyActivate());
michael@0: 
michael@0:   log.AppendPrintf("    npncomplete = %d  setupSSLCalled = %d\n",
michael@0:                    mNPNComplete, mSetupSSLCalled);
michael@0: 
michael@0:   log.AppendPrintf("    spdyVersion = %d  reportedSpdy = %d everspdy = %d\n",
michael@0:                    mUsingSpdyVersion, mReportedSpdy, mEverUsedSpdy);
michael@0: 
michael@0:   log.AppendPrintf("    iskeepalive = %d  dontReuse = %d isReused = %d\n",
michael@0:                    IsKeepAlive(), mDontReuse, mIsReused);
michael@0: 
michael@0:   log.AppendPrintf("    mTransaction = %d mSpdySession = %d\n",
michael@0:                    !!mTransaction.get(), !!mSpdySession.get());
michael@0: 
michael@0:   PRIntervalTime now = PR_IntervalNow();
michael@0:   log.AppendPrintf("    time since last read = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastReadTime));
michael@0: 
michael@0:   log.AppendPrintf("    max-read/read/written %lld/%lld/%lld\n",
michael@0:                    mMaxBytesRead, mTotalBytesRead, mTotalBytesWritten);
michael@0: 
michael@0:   log.AppendPrintf("    rtt = %ums\n", PR_IntervalToMilliseconds(mRtt));
michael@0: 
michael@0:   log.AppendPrintf("    idlemonitoring = %d transactionCount=%d\n",
michael@0:                    mIdleMonitoring, mHttp1xTransactionCount);
michael@0: 
michael@0:   log.AppendPrintf("    supports pipeline = %d classification = 0x%x\n",
michael@0:                    mSupportsPipelining, mClassification);
michael@0: 
michael@0:   if (mSpdySession)
michael@0:     mSpdySession->PrintDiagnostics(log);
michael@0: }
michael@0: 
michael@0: 
michael@0: void
michael@0: SpdySession3::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   log.AppendPrintf("     ::: SPDY VERSION 3\n");
michael@0:   log.AppendPrintf("     shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
michael@0:                    mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
michael@0: 
michael@0:   log.AppendPrintf("     concurrent = %d maxconcurrent = %d\n",
michael@0:                    mConcurrent, mMaxConcurrent);
michael@0: 
michael@0:   log.AppendPrintf("     roomformorestreams = %d roomformoreconcurrent = %d\n",
michael@0:                    RoomForMoreStreams(), RoomForMoreConcurrent());
michael@0: 
michael@0:   log.AppendPrintf("     transactionHashCount = %d streamIDHashCount = %d\n",
michael@0:                    mStreamTransactionHash.Count(),
michael@0:                    mStreamIDHash.Count());
michael@0: 
michael@0:   log.AppendPrintf("     Queued Stream Size = %d\n", mQueuedStreams.GetSize());
michael@0: 
michael@0:   PRIntervalTime now = PR_IntervalNow();
michael@0:   log.AppendPrintf("     Ping Threshold = %ums next ping id = 0x%X\n",
michael@0:                    PR_IntervalToMilliseconds(mPingThreshold),
michael@0:                    mNextPingID);
michael@0:   log.AppendPrintf("     Ping Timeout = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
michael@0:   log.AppendPrintf("     Idle for Any Activity (ping) = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastReadEpoch));
michael@0:   log.AppendPrintf("     Idle for Data Activity = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
michael@0:   if (mPingSentEpoch)
michael@0:     log.AppendPrintf("     Ping Outstanding (ping) = %ums, expired = %d\n",
michael@0:                      PR_IntervalToMilliseconds(now - mPingSentEpoch),
michael@0:                      now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
michael@0:   else
michael@0:     log.AppendPrintf("     No Ping Outstanding\n");
michael@0: }
michael@0: 
michael@0: void
michael@0: SpdySession31::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   log.AppendPrintf("     ::: SPDY VERSION 3.1\n");
michael@0:   log.AppendPrintf("     shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
michael@0:                    mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
michael@0: 
michael@0:   log.AppendPrintf("     concurrent = %d maxconcurrent = %d\n",
michael@0:                    mConcurrent, mMaxConcurrent);
michael@0: 
michael@0:   log.AppendPrintf("     roomformorestreams = %d roomformoreconcurrent = %d\n",
michael@0:                    RoomForMoreStreams(), RoomForMoreConcurrent());
michael@0: 
michael@0:   log.AppendPrintf("     transactionHashCount = %d streamIDHashCount = %d\n",
michael@0:                    mStreamTransactionHash.Count(),
michael@0:                    mStreamIDHash.Count());
michael@0: 
michael@0:   log.AppendPrintf("     Queued Stream Size = %d\n", mQueuedStreams.GetSize());
michael@0: 
michael@0:   PRIntervalTime now = PR_IntervalNow();
michael@0:   log.AppendPrintf("     Ping Threshold = %ums next ping id = 0x%X\n",
michael@0:                    PR_IntervalToMilliseconds(mPingThreshold),
michael@0:                    mNextPingID);
michael@0:   log.AppendPrintf("     Ping Timeout = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
michael@0:   log.AppendPrintf("     Idle for Any Activity (ping) = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastReadEpoch));
michael@0:   log.AppendPrintf("     Idle for Data Activity = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
michael@0:   if (mPingSentEpoch)
michael@0:     log.AppendPrintf("     Ping Outstanding (ping) = %ums, expired = %d\n",
michael@0:                      PR_IntervalToMilliseconds(now - mPingSentEpoch),
michael@0:                      now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
michael@0:   else
michael@0:     log.AppendPrintf("     No Ping Outstanding\n");
michael@0: }
michael@0: 
michael@0: void
michael@0: Http2Session::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   log.AppendPrintf("     ::: HTTP2\n");
michael@0:   log.AppendPrintf("     shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
michael@0:                    mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
michael@0: 
michael@0:   log.AppendPrintf("     concurrent = %d maxconcurrent = %d\n",
michael@0:                    mConcurrent, mMaxConcurrent);
michael@0: 
michael@0:   log.AppendPrintf("     roomformorestreams = %d roomformoreconcurrent = %d\n",
michael@0:                    RoomForMoreStreams(), RoomForMoreConcurrent());
michael@0: 
michael@0:   log.AppendPrintf("     transactionHashCount = %d streamIDHashCount = %d\n",
michael@0:                    mStreamTransactionHash.Count(),
michael@0:                    mStreamIDHash.Count());
michael@0: 
michael@0:   log.AppendPrintf("     Queued Stream Size = %d\n", mQueuedStreams.GetSize());
michael@0: 
michael@0:   PRIntervalTime now = PR_IntervalNow();
michael@0:   log.AppendPrintf("     Ping Threshold = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(mPingThreshold));
michael@0:   log.AppendPrintf("     Ping Timeout = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
michael@0:   log.AppendPrintf("     Idle for Any Activity (ping) = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastReadEpoch));
michael@0:   log.AppendPrintf("     Idle for Data Activity = %ums\n",
michael@0:                    PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
michael@0:   if (mPingSentEpoch)
michael@0:     log.AppendPrintf("     Ping Outstanding (ping) = %ums, expired = %d\n",
michael@0:                      PR_IntervalToMilliseconds(now - mPingSentEpoch),
michael@0:                      now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
michael@0:   else
michael@0:     log.AppendPrintf("     No Ping Outstanding\n");
michael@0: }
michael@0: 
michael@0: void
michael@0: nsHttpTransaction::PrintDiagnostics(nsCString &log)
michael@0: {
michael@0:   if (!mRequestHead)
michael@0:     return;
michael@0: 
michael@0:   log.AppendPrintf("     ::: uri = %s\n",
michael@0:                    nsAutoCString(mRequestHead->RequestURI()).get());
michael@0:   log.AppendPrintf("     caps = 0x%x\n", mCaps);
michael@0:   log.AppendPrintf("     priority = %d\n", mPriority);
michael@0:   log.AppendPrintf("     restart count = %u\n", mRestartCount);
michael@0:   log.AppendPrintf("     classification = 0x%x\n", mClassification);
michael@0: }
michael@0: 
michael@0: } // namespace mozilla::net
michael@0: } // namespace mozilla