1 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
2 /* vim: set sw=2 ts=8 et tw=80 : */
3 /* This Source Code Form is subject to the terms of the Mozilla Public
4  * License, v. 2.0. If a copy of the MPL was not distributed with this
5  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
6 
7 // HttpLog.h should generally be included first
8 #include "HttpLog.h"
9 
10 #include "nsHttpConnectionMgr.h"
11 #include "nsHttpConnection.h"
12 #include "Http2Session.h"
13 #include "nsHttpHandler.h"
14 #include "nsIConsoleService.h"
15 #include "nsHttpRequestHead.h"
16 #include "nsServiceManagerUtils.h"
17 #include "nsSocketTransportService2.h"
18 
19 #include "mozilla/IntegerPrintfMacros.h"
20 
21 namespace mozilla {
22 namespace net {
23 
PrintDiagnostics()24 void nsHttpConnectionMgr::PrintDiagnostics() {
25   nsresult rv =
26       PostEvent(&nsHttpConnectionMgr::OnMsgPrintDiagnostics, 0, nullptr);
27   if (NS_FAILED(rv)) {
28     LOG(
29         ("nsHttpConnectionMgr::PrintDiagnostics\n"
30          "  failed to post OnMsgPrintDiagnostics event"));
31   }
32 }
33 
OnMsgPrintDiagnostics(int32_t,ARefBase *)34 void nsHttpConnectionMgr::OnMsgPrintDiagnostics(int32_t, ARefBase *) {
35   MOZ_ASSERT(OnSocketThread(), "not on socket thread");
36 
37   nsCOMPtr<nsIConsoleService> consoleService =
38       do_GetService(NS_CONSOLESERVICE_CONTRACTID);
39   if (!consoleService) return;
40 
41   mLogData.AppendPrintf("HTTP Connection Diagnostics\n---------------------\n");
42   mLogData.AppendPrintf("IsSpdyEnabled() = %d\n",
43                         gHttpHandler->IsSpdyEnabled());
44   mLogData.AppendPrintf("MaxSocketCount() = %d\n",
45                         gHttpHandler->MaxSocketCount());
46   mLogData.AppendPrintf("mNumActiveConns = %d\n", mNumActiveConns);
47   mLogData.AppendPrintf("mNumIdleConns = %d\n", mNumIdleConns);
48 
49   for (auto iter = mCT.Iter(); !iter.Done(); iter.Next()) {
50     RefPtr<nsConnectionEntry> ent = iter.Data();
51 
52     mLogData.AppendPrintf(" ent host = %s hashkey = %s\n",
53                           ent->mConnInfo->Origin(),
54                           ent->mConnInfo->HashKey().get());
55     mLogData.AppendPrintf(
56         "   AtActiveConnectionLimit = %d\n",
57         AtActiveConnectionLimit(ent, NS_HTTP_ALLOW_KEEPALIVE));
58     mLogData.AppendPrintf("   RestrictConnections = %d\n",
59                           RestrictConnections(ent));
60     mLogData.AppendPrintf("   Pending Q Length = %zu\n", ent->PendingQLength());
61     mLogData.AppendPrintf("   Active Conns Length = %zu\n",
62                           ent->mActiveConns.Length());
63     mLogData.AppendPrintf("   Idle Conns Length = %zu\n",
64                           ent->mIdleConns.Length());
65     mLogData.AppendPrintf("   Half Opens Length = %zu\n",
66                           ent->mHalfOpens.Length());
67     mLogData.AppendPrintf("   Coalescing Keys Length = %zu\n",
68                           ent->mCoalescingKeys.Length());
69     mLogData.AppendPrintf("   Spdy using = %d\n", ent->mUsingSpdy);
70 
71     uint32_t i;
72     for (i = 0; i < ent->mActiveConns.Length(); ++i) {
73       mLogData.AppendPrintf("   :: Active Connection #%u\n", i);
74       ent->mActiveConns[i]->PrintDiagnostics(mLogData);
75     }
76     for (i = 0; i < ent->mIdleConns.Length(); ++i) {
77       mLogData.AppendPrintf("   :: Idle Connection #%u\n", i);
78       ent->mIdleConns[i]->PrintDiagnostics(mLogData);
79     }
80     for (i = 0; i < ent->mHalfOpens.Length(); ++i) {
81       mLogData.AppendPrintf("   :: Half Open #%u\n", i);
82       ent->mHalfOpens[i]->PrintDiagnostics(mLogData);
83     }
84     i = 0;
85     for (auto it = ent->mPendingTransactionTable.Iter(); !it.Done();
86          it.Next()) {
87       mLogData.AppendPrintf(
88           "   :: Pending Transactions with Window ID = %" PRIu64 "\n",
89           it.Key());
90       for (uint32_t j = 0; j < it.UserData()->Length(); ++j) {
91         mLogData.AppendPrintf("     ::: Pending Transaction #%u\n", i);
92         it.UserData()->ElementAt(j)->PrintDiagnostics(mLogData);
93         ++i;
94       }
95     }
96     for (i = 0; i < ent->mCoalescingKeys.Length(); ++i) {
97       mLogData.AppendPrintf("   :: Coalescing Key #%u %s\n", i,
98                             ent->mCoalescingKeys[i].get());
99     }
100   }
101 
102   consoleService->LogStringMessage(NS_ConvertUTF8toUTF16(mLogData).Data());
103   mLogData.Truncate();
104 }
105 
PrintDiagnostics(nsCString & log)106 void nsHttpConnectionMgr::nsHalfOpenSocket::PrintDiagnostics(nsCString &log) {
107   log.AppendPrintf("     has connected = %d, isSpeculative = %d\n",
108                    HasConnected(), IsSpeculative());
109 
110   TimeStamp now = TimeStamp::Now();
111 
112   if (mPrimarySynStarted.IsNull())
113     log.AppendPrintf("    primary not started\n");
114   else
115     log.AppendPrintf("    primary started %.2fms ago\n",
116                      (now - mPrimarySynStarted).ToMilliseconds());
117 
118   if (mBackupSynStarted.IsNull())
119     log.AppendPrintf("    backup not started\n");
120   else
121     log.AppendPrintf("    backup started %.2f ago\n",
122                      (now - mBackupSynStarted).ToMilliseconds());
123 
124   log.AppendPrintf("    primary transport %d, backup transport %d\n",
125                    !!mSocketTransport.get(), !!mBackupTransport.get());
126 }
127 
PrintDiagnostics(nsCString & log)128 void nsHttpConnection::PrintDiagnostics(nsCString &log) {
129   log.AppendPrintf("    CanDirectlyActivate = %d\n", CanDirectlyActivate());
130 
131   log.AppendPrintf("    npncomplete = %d  setupSSLCalled = %d\n", mNPNComplete,
132                    mSetupSSLCalled);
133 
134   log.AppendPrintf("    spdyVersion = %d  reportedSpdy = %d everspdy = %d\n",
135                    mUsingSpdyVersion, mReportedSpdy, mEverUsedSpdy);
136 
137   log.AppendPrintf("    iskeepalive = %d  dontReuse = %d isReused = %d\n",
138                    IsKeepAlive(), mDontReuse, mIsReused);
139 
140   log.AppendPrintf("    mTransaction = %d mSpdySession = %d\n",
141                    !!mTransaction.get(), !!mSpdySession.get());
142 
143   PRIntervalTime now = PR_IntervalNow();
144   log.AppendPrintf("    time since last read = %ums\n",
145                    PR_IntervalToMilliseconds(now - mLastReadTime));
146 
147   log.AppendPrintf("    max-read/read/written %" PRId64 "/%" PRId64 "/%" PRId64
148                    "\n",
149                    mMaxBytesRead, mTotalBytesRead, mTotalBytesWritten);
150 
151   log.AppendPrintf("    rtt = %ums\n", PR_IntervalToMilliseconds(mRtt));
152 
153   log.AppendPrintf("    idlemonitoring = %d transactionCount=%d\n",
154                    mIdleMonitoring, mHttp1xTransactionCount);
155 
156   if (mSpdySession) mSpdySession->PrintDiagnostics(log);
157 }
158 
PrintDiagnostics(nsCString & log)159 void Http2Session::PrintDiagnostics(nsCString &log) {
160   log.AppendPrintf("     ::: HTTP2\n");
161   log.AppendPrintf(
162       "     shouldgoaway = %d mClosed = %d CanReuse = %d nextID=0x%X\n",
163       mShouldGoAway, mClosed, CanReuse(), mNextStreamID);
164 
165   log.AppendPrintf("     concurrent = %d maxconcurrent = %d\n", mConcurrent,
166                    mMaxConcurrent);
167 
168   log.AppendPrintf("     roomformorestreams = %d roomformoreconcurrent = %d\n",
169                    RoomForMoreStreams(), RoomForMoreConcurrent());
170 
171   log.AppendPrintf("     transactionHashCount = %d streamIDHashCount = %d\n",
172                    mStreamTransactionHash.Count(), mStreamIDHash.Count());
173 
174   log.AppendPrintf("     Queued Stream Size = %zu\n", mQueuedStreams.GetSize());
175 
176   PRIntervalTime now = PR_IntervalNow();
177   log.AppendPrintf("     Ping Threshold = %ums\n",
178                    PR_IntervalToMilliseconds(mPingThreshold));
179   log.AppendPrintf("     Ping Timeout = %ums\n",
180                    PR_IntervalToMilliseconds(gHttpHandler->SpdyPingTimeout()));
181   log.AppendPrintf("     Idle for Any Activity (ping) = %ums\n",
182                    PR_IntervalToMilliseconds(now - mLastReadEpoch));
183   log.AppendPrintf("     Idle for Data Activity = %ums\n",
184                    PR_IntervalToMilliseconds(now - mLastDataReadEpoch));
185   if (mPingSentEpoch)
186     log.AppendPrintf("     Ping Outstanding (ping) = %ums, expired = %d\n",
187                      PR_IntervalToMilliseconds(now - mPingSentEpoch),
188                      now - mPingSentEpoch >= gHttpHandler->SpdyPingTimeout());
189   else
190     log.AppendPrintf("     No Ping Outstanding\n");
191 }
192 
PrintDiagnostics(nsCString & log)193 void nsHttpTransaction::PrintDiagnostics(nsCString &log) {
194   if (!mRequestHead) return;
195 
196   nsAutoCString requestURI;
197   mRequestHead->RequestURI(requestURI);
198   log.AppendPrintf("       :::: uri = %s\n", requestURI.get());
199   log.AppendPrintf("       caps = 0x%x\n", mCaps);
200   log.AppendPrintf("       priority = %d\n", mPriority);
201   log.AppendPrintf("       restart count = %u\n", mRestartCount);
202 }
203 
PrintDiagnostics(nsCString & log)204 void nsHttpConnectionMgr::PendingTransactionInfo::PrintDiagnostics(
205     nsCString &log) {
206   log.AppendPrintf("     ::: Pending transaction\n");
207   mTransaction->PrintDiagnostics(log);
208   RefPtr<nsHalfOpenSocket> halfOpen = do_QueryReferent(mHalfOpen);
209   log.AppendPrintf("     Waiting for half open sock: %p or connection: %p\n",
210                    halfOpen.get(), mActiveConn.get());
211 }
212 
213 }  // namespace net
214 }  // namespace mozilla
215