| OLD | NEW |
| 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. |
| 2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
| 3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
| 4 | 4 |
| 5 #include "extensions/browser/api/web_request/web_request_time_tracker.h" | 5 #include "extensions/browser/api/web_request/web_request_time_tracker.h" |
| 6 | 6 |
| 7 #include "base/bind.h" | 7 #include "base/bind.h" |
| 8 #include "base/compiler_specific.h" | 8 #include "base/compiler_specific.h" |
| 9 #include "base/metrics/histogram.h" | 9 #include "base/metrics/histogram.h" |
| 10 #include "extensions/browser/warning_set.h" | 10 #include "extensions/browser/warning_set.h" |
| (...skipping 82 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 93 } | 93 } |
| 94 | 94 |
| 95 ExtensionWebRequestTimeTracker::ExtensionWebRequestTimeTracker() | 95 ExtensionWebRequestTimeTracker::ExtensionWebRequestTimeTracker() |
| 96 : delegate_(new DefaultDelegate) { | 96 : delegate_(new DefaultDelegate) { |
| 97 } | 97 } |
| 98 | 98 |
| 99 ExtensionWebRequestTimeTracker::~ExtensionWebRequestTimeTracker() { | 99 ExtensionWebRequestTimeTracker::~ExtensionWebRequestTimeTracker() { |
| 100 } | 100 } |
| 101 | 101 |
| 102 void ExtensionWebRequestTimeTracker::LogRequestStartTime( | 102 void ExtensionWebRequestTimeTracker::LogRequestStartTime( |
| 103 int64 request_id, | 103 int64_t request_id, |
| 104 const base::Time& start_time, | 104 const base::Time& start_time, |
| 105 const GURL& url, | 105 const GURL& url, |
| 106 void* profile) { | 106 void* profile) { |
| 107 // Trim old completed request logs. | 107 // Trim old completed request logs. |
| 108 while (request_ids_.size() > kMaxRequestsLogged) { | 108 while (request_ids_.size() > kMaxRequestsLogged) { |
| 109 int64 to_remove = request_ids_.front(); | 109 int64_t to_remove = request_ids_.front(); |
| 110 request_ids_.pop(); | 110 request_ids_.pop(); |
| 111 std::map<int64, RequestTimeLog>::iterator iter = | 111 std::map<int64_t, RequestTimeLog>::iterator iter = |
| 112 request_time_logs_.find(to_remove); | 112 request_time_logs_.find(to_remove); |
| 113 if (iter != request_time_logs_.end() && iter->second.completed) { | 113 if (iter != request_time_logs_.end() && iter->second.completed) { |
| 114 request_time_logs_.erase(iter); | 114 request_time_logs_.erase(iter); |
| 115 moderate_delays_.erase(to_remove); | 115 moderate_delays_.erase(to_remove); |
| 116 excessive_delays_.erase(to_remove); | 116 excessive_delays_.erase(to_remove); |
| 117 } | 117 } |
| 118 } | 118 } |
| 119 request_ids_.push(request_id); | 119 request_ids_.push(request_id); |
| 120 | 120 |
| 121 if (request_time_logs_.find(request_id) != request_time_logs_.end()) { | 121 if (request_time_logs_.find(request_id) != request_time_logs_.end()) { |
| 122 RequestTimeLog& log = request_time_logs_[request_id]; | 122 RequestTimeLog& log = request_time_logs_[request_id]; |
| 123 DCHECK(!log.completed); | 123 DCHECK(!log.completed); |
| 124 return; | 124 return; |
| 125 } | 125 } |
| 126 RequestTimeLog& log = request_time_logs_[request_id]; | 126 RequestTimeLog& log = request_time_logs_[request_id]; |
| 127 log.request_start_time = start_time; | 127 log.request_start_time = start_time; |
| 128 log.url = url; | 128 log.url = url; |
| 129 log.profile = profile; | 129 log.profile = profile; |
| 130 } | 130 } |
| 131 | 131 |
| 132 void ExtensionWebRequestTimeTracker::LogRequestEndTime( | 132 void ExtensionWebRequestTimeTracker::LogRequestEndTime( |
| 133 int64 request_id, const base::Time& end_time) { | 133 int64_t request_id, |
| 134 const base::Time& end_time) { |
| 134 if (request_time_logs_.find(request_id) == request_time_logs_.end()) | 135 if (request_time_logs_.find(request_id) == request_time_logs_.end()) |
| 135 return; | 136 return; |
| 136 | 137 |
| 137 RequestTimeLog& log = request_time_logs_[request_id]; | 138 RequestTimeLog& log = request_time_logs_[request_id]; |
| 138 if (log.completed) | 139 if (log.completed) |
| 139 return; | 140 return; |
| 140 | 141 |
| 141 log.request_duration = end_time - log.request_start_time; | 142 log.request_duration = end_time - log.request_start_time; |
| 142 log.completed = true; | 143 log.completed = true; |
| 143 | 144 |
| (...skipping 10 matching lines...) Expand all Loading... |
| 154 std::set<std::string> result; | 155 std::set<std::string> result; |
| 155 for (std::map<std::string, base::TimeDelta>::const_iterator i = | 156 for (std::map<std::string, base::TimeDelta>::const_iterator i = |
| 156 log.extension_block_durations.begin(); | 157 log.extension_block_durations.begin(); |
| 157 i != log.extension_block_durations.end(); | 158 i != log.extension_block_durations.end(); |
| 158 ++i) { | 159 ++i) { |
| 159 result.insert(i->first); | 160 result.insert(i->first); |
| 160 } | 161 } |
| 161 return result; | 162 return result; |
| 162 } | 163 } |
| 163 | 164 |
| 164 void ExtensionWebRequestTimeTracker::Analyze(int64 request_id) { | 165 void ExtensionWebRequestTimeTracker::Analyze(int64_t request_id) { |
| 165 RequestTimeLog& log = request_time_logs_[request_id]; | 166 RequestTimeLog& log = request_time_logs_[request_id]; |
| 166 | 167 |
| 167 // Ignore really short requests. Time spent on these is negligible, and any | 168 // Ignore really short requests. Time spent on these is negligible, and any |
| 168 // extra delay the extension adds is likely to be noise. | 169 // extra delay the extension adds is likely to be noise. |
| 169 if (log.request_duration.InMilliseconds() < kMinRequestTimeToCareMs) | 170 if (log.request_duration.InMilliseconds() < kMinRequestTimeToCareMs) |
| 170 return; | 171 return; |
| 171 | 172 |
| 172 double percentage = | 173 double percentage = |
| 173 log.block_duration.InMillisecondsF() / | 174 log.block_duration.InMillisecondsF() / |
| 174 log.request_duration.InMillisecondsF(); | 175 log.request_duration.InMillisecondsF(); |
| (...skipping 27 matching lines...) Expand all Loading... |
| 202 moderate_delays_.size() + excessive_delays_.size(), | 203 moderate_delays_.size() + excessive_delays_.size(), |
| 203 request_ids_.size(), | 204 request_ids_.size(), |
| 204 GetExtensionIds(log)); | 205 GetExtensionIds(log)); |
| 205 } | 206 } |
| 206 } | 207 } |
| 207 } | 208 } |
| 208 } | 209 } |
| 209 | 210 |
| 210 void ExtensionWebRequestTimeTracker::IncrementExtensionBlockTime( | 211 void ExtensionWebRequestTimeTracker::IncrementExtensionBlockTime( |
| 211 const std::string& extension_id, | 212 const std::string& extension_id, |
| 212 int64 request_id, | 213 int64_t request_id, |
| 213 const base::TimeDelta& block_time) { | 214 const base::TimeDelta& block_time) { |
| 214 if (request_time_logs_.find(request_id) == request_time_logs_.end()) | 215 if (request_time_logs_.find(request_id) == request_time_logs_.end()) |
| 215 return; | 216 return; |
| 216 RequestTimeLog& log = request_time_logs_[request_id]; | 217 RequestTimeLog& log = request_time_logs_[request_id]; |
| 217 log.extension_block_durations[extension_id] += block_time; | 218 log.extension_block_durations[extension_id] += block_time; |
| 218 } | 219 } |
| 219 | 220 |
| 220 void ExtensionWebRequestTimeTracker::IncrementTotalBlockTime( | 221 void ExtensionWebRequestTimeTracker::IncrementTotalBlockTime( |
| 221 int64 request_id, | 222 int64_t request_id, |
| 222 const base::TimeDelta& block_time) { | 223 const base::TimeDelta& block_time) { |
| 223 if (request_time_logs_.find(request_id) == request_time_logs_.end()) | 224 if (request_time_logs_.find(request_id) == request_time_logs_.end()) |
| 224 return; | 225 return; |
| 225 RequestTimeLog& log = request_time_logs_[request_id]; | 226 RequestTimeLog& log = request_time_logs_[request_id]; |
| 226 log.block_duration += block_time; | 227 log.block_duration += block_time; |
| 227 } | 228 } |
| 228 | 229 |
| 229 void ExtensionWebRequestTimeTracker::SetRequestCanceled(int64 request_id) { | 230 void ExtensionWebRequestTimeTracker::SetRequestCanceled(int64_t request_id) { |
| 230 // Canceled requests won't actually hit the network, so we can't compare | 231 // Canceled requests won't actually hit the network, so we can't compare |
| 231 // their request time to the time spent waiting on the extension. Just ignore | 232 // their request time to the time spent waiting on the extension. Just ignore |
| 232 // them. | 233 // them. |
| 233 // TODO(mpcomplete): may want to count cancels as "bonuses" for an extension. | 234 // TODO(mpcomplete): may want to count cancels as "bonuses" for an extension. |
| 234 // i.e. if it slows down 50% of requests but cancels 25% of the rest, that | 235 // i.e. if it slows down 50% of requests but cancels 25% of the rest, that |
| 235 // might average out to only being "25% slow". | 236 // might average out to only being "25% slow". |
| 236 request_time_logs_.erase(request_id); | 237 request_time_logs_.erase(request_id); |
| 237 } | 238 } |
| 238 | 239 |
| 239 void ExtensionWebRequestTimeTracker::SetRequestRedirected(int64 request_id) { | 240 void ExtensionWebRequestTimeTracker::SetRequestRedirected(int64_t request_id) { |
| 240 // When a request is redirected, we have no way of knowing how long the | 241 // When a request is redirected, we have no way of knowing how long the |
| 241 // request would have taken, so we can't say how much an extension slowed | 242 // request would have taken, so we can't say how much an extension slowed |
| 242 // down this request. Just ignore it. | 243 // down this request. Just ignore it. |
| 243 request_time_logs_.erase(request_id); | 244 request_time_logs_.erase(request_id); |
| 244 } | 245 } |
| 245 | 246 |
| 246 void ExtensionWebRequestTimeTracker::SetDelegate( | 247 void ExtensionWebRequestTimeTracker::SetDelegate( |
| 247 ExtensionWebRequestTimeTrackerDelegate* delegate) { | 248 ExtensionWebRequestTimeTrackerDelegate* delegate) { |
| 248 delegate_.reset(delegate); | 249 delegate_.reset(delegate); |
| 249 } | 250 } |
| OLD | NEW |