Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 1 | // Copyright (c) 2013 The Chromium OS Authors. All rights reserved. |
| 2 | // Use of this source code is governed by a BSD-style license that can be |
| 3 | // found in the LICENSE file. |
| 4 | |
| 5 | #include "shill/traffic_monitor.h" |
| 6 | |
| 7 | #include <base/bind.h> |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 8 | #include <base/stringprintf.h> |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 9 | #include <netinet/in.h> |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 10 | |
| 11 | #include "shill/device.h" |
| 12 | #include "shill/device_info.h" |
| 13 | #include "shill/event_dispatcher.h" |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 14 | #include "shill/logging.h" |
| 15 | #include "shill/socket_info_reader.h" |
| 16 | |
| 17 | using base::StringPrintf; |
| 18 | using std::string; |
| 19 | using std::vector; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 20 | |
| 21 | namespace shill { |
| 22 | |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 23 | // static |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 24 | const uint16 TrafficMonitor::kDnsPort = 53; |
| 25 | const int64 TrafficMonitor::kDnsTimedOutThresholdSeconds = 15; |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 26 | const int TrafficMonitor::kMinimumFailedSamplesToTrigger = 2; |
| 27 | const int64 TrafficMonitor::kSamplingIntervalMilliseconds = 5000; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 28 | |
| 29 | TrafficMonitor::TrafficMonitor(const DeviceRefPtr &device, |
| 30 | EventDispatcher *dispatcher) |
| 31 | : device_(device), |
| 32 | dispatcher_(dispatcher), |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 33 | socket_info_reader_(new SocketInfoReader), |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 34 | accummulated_congested_tx_queues_samples_(0), |
| 35 | connection_info_reader_(new ConnectionInfoReader), |
| 36 | accummulated_dns_failures_samples_(0) { |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 37 | } |
| 38 | |
| 39 | TrafficMonitor::~TrafficMonitor() { |
| 40 | Stop(); |
| 41 | } |
| 42 | |
| 43 | void TrafficMonitor::Start() { |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 44 | SLOG(Link, 2) << __func__; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 45 | Stop(); |
| 46 | |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 47 | sample_traffic_callback_.Reset(base::Bind(&TrafficMonitor::SampleTraffic, |
| 48 | base::Unretained(this))); |
| 49 | dispatcher_->PostDelayedTask(sample_traffic_callback_.callback(), |
| 50 | kSamplingIntervalMilliseconds); |
| 51 | } |
| 52 | |
| 53 | void TrafficMonitor::Stop() { |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 54 | SLOG(Link, 2) << __func__; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 55 | sample_traffic_callback_.Cancel(); |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 56 | ResetCongestedTxQueuesStats(); |
| 57 | ResetDnsFailingStats(); |
| 58 | } |
| 59 | |
| 60 | void TrafficMonitor::ResetCongestedTxQueuesStats() { |
| 61 | accummulated_congested_tx_queues_samples_ = 0; |
| 62 | } |
| 63 | |
| 64 | void TrafficMonitor::ResetCongestedTxQueuesStatsWithLogging() { |
| 65 | SLOG(Link, 2) << __func__ << ": Tx-queues decongested"; |
| 66 | ResetCongestedTxQueuesStats(); |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 67 | } |
| 68 | |
| 69 | void TrafficMonitor::BuildIPPortToTxQueueLength( |
| 70 | const vector<SocketInfo> &socket_infos, |
| 71 | IPPortToTxQueueLengthMap *tx_queue_lengths) { |
Arman Uguray | d42d8ec | 2013-04-08 19:28:21 -0700 | [diff] [blame] | 72 | SLOG(Link, 3) << __func__; |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 73 | string device_ip_address = device_->ipconfig()->properties().address; |
| 74 | vector<SocketInfo>::const_iterator it; |
| 75 | for (it = socket_infos.begin(); it != socket_infos.end(); ++it) { |
Arman Uguray | d42d8ec | 2013-04-08 19:28:21 -0700 | [diff] [blame] | 76 | SLOG(Link, 4) << "SocketInfo(IP=" << it->local_ip_address().ToString() |
| 77 | << ", TX=" << it->transmit_queue_value() |
| 78 | << ", State=" << it->connection_state() |
| 79 | << ", TimerState=" << it->timer_state(); |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 80 | if (it->local_ip_address().ToString() != device_ip_address || |
| 81 | it->transmit_queue_value() == 0 || |
| 82 | it->connection_state() != SocketInfo::kConnectionStateEstablished || |
Arman Uguray | d42d8ec | 2013-04-08 19:28:21 -0700 | [diff] [blame] | 83 | (it->timer_state() != SocketInfo::kTimerStateRetransmitTimerPending && |
| 84 | it->timer_state() != |
| 85 | SocketInfo::kTimerStateZeroWindowProbeTimerPending)) { |
| 86 | SLOG(Link, 4) << "Connection Filtered."; |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 87 | continue; |
Arman Uguray | d42d8ec | 2013-04-08 19:28:21 -0700 | [diff] [blame] | 88 | } |
| 89 | SLOG(Link, 3) << "Monitoring connection: TX=" << it->transmit_queue_value() |
| 90 | << " TimerState=" << it->timer_state(); |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 91 | |
| 92 | string local_ip_port = |
| 93 | StringPrintf("%s:%d", |
| 94 | it->local_ip_address().ToString().c_str(), |
| 95 | it->local_port()); |
| 96 | (*tx_queue_lengths)[local_ip_port] = it->transmit_queue_value(); |
| 97 | } |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 98 | } |
| 99 | |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 100 | bool TrafficMonitor::IsCongestedTxQueues() { |
| 101 | SLOG(Link, 4) << __func__; |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 102 | vector<SocketInfo> socket_infos; |
| 103 | if (!socket_info_reader_->LoadTcpSocketInfo(&socket_infos) || |
| 104 | socket_infos.empty()) { |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 105 | SLOG(Link, 3) << __func__ << ": Empty socket info"; |
| 106 | ResetCongestedTxQueuesStatsWithLogging(); |
| 107 | return false; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 108 | } |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 109 | bool congested_tx_queues = true; |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 110 | IPPortToTxQueueLengthMap curr_tx_queue_lengths; |
| 111 | BuildIPPortToTxQueueLength(socket_infos, &curr_tx_queue_lengths); |
| 112 | if (curr_tx_queue_lengths.empty()) { |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 113 | SLOG(Link, 3) << __func__ << ": No interesting socket info"; |
| 114 | ResetCongestedTxQueuesStatsWithLogging(); |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 115 | } else { |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 116 | IPPortToTxQueueLengthMap::iterator old_tx_queue_it; |
| 117 | for (old_tx_queue_it = old_tx_queue_lengths_.begin(); |
| 118 | old_tx_queue_it != old_tx_queue_lengths_.end(); |
| 119 | ++old_tx_queue_it) { |
| 120 | IPPortToTxQueueLengthMap::iterator curr_tx_queue_it = |
| 121 | curr_tx_queue_lengths.find(old_tx_queue_it->first); |
| 122 | if (curr_tx_queue_it == curr_tx_queue_lengths.end() || |
| 123 | curr_tx_queue_it->second < old_tx_queue_it->second) { |
| 124 | congested_tx_queues = false; |
Arman Uguray | f84a424 | 2013-04-09 20:01:07 -0700 | [diff] [blame] | 125 | // TODO(armansito): If we had a false positive earlier, we may |
| 126 | // want to correct it here by invoking a "connection back to normal |
| 127 | // callback", so that the OutOfCredits property can be set to |
| 128 | // false. |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 129 | break; |
| 130 | } |
| 131 | } |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 132 | if (congested_tx_queues) { |
| 133 | ++accummulated_congested_tx_queues_samples_; |
| 134 | SLOG(Link, 2) << __func__ |
| 135 | << ": Congested tx-queues detected (" |
| 136 | << accummulated_congested_tx_queues_samples_ << ")"; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 137 | } |
| 138 | } |
Thieu Le | 0302666 | 2013-04-04 10:45:11 -0700 | [diff] [blame] | 139 | old_tx_queue_lengths_ = curr_tx_queue_lengths; |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 140 | |
Thieu Le | fa7960e | 2013-04-15 13:14:55 -0700 | [diff] [blame] | 141 | return congested_tx_queues; |
| 142 | } |
| 143 | |
| 144 | void TrafficMonitor::ResetDnsFailingStats() { |
| 145 | accummulated_dns_failures_samples_ = 0; |
| 146 | } |
| 147 | |
| 148 | void TrafficMonitor::ResetDnsFailingStatsWithLogging() { |
| 149 | SLOG(Link, 2) << __func__ << ": DNS queries restored"; |
| 150 | ResetDnsFailingStats(); |
| 151 | } |
| 152 | |
| 153 | bool TrafficMonitor::IsDnsFailing() { |
| 154 | SLOG(Link, 4) << __func__; |
| 155 | vector<ConnectionInfo> connection_infos; |
| 156 | if (!connection_info_reader_->LoadConnectionInfo(&connection_infos) || |
| 157 | connection_infos.empty()) { |
| 158 | SLOG(Link, 3) << __func__ << ": Empty connection info"; |
| 159 | } else { |
| 160 | // The time-to-expire counter is used to determine when a DNS request |
| 161 | // has timed out. This counter is the number of seconds remaining until |
| 162 | // the entry is removed from the system IP connection tracker. The |
| 163 | // default time is 30 seconds. This is too long of a wait. Instead, we |
| 164 | // want to time out at |kDnsTimedOutThresholdSeconds|. Unfortunately, |
| 165 | // we cannot simply look for entries less than |
| 166 | // |kDnsTimedOutThresholdSeconds| because we will count the entry |
| 167 | // multiple times once its time-to-expire is less than |
| 168 | // |kDnsTimedOutThresholdSeconds|. To ensure that we only count an |
| 169 | // entry once, we look for entries in this time window between |
| 170 | // |kDnsTimedOutThresholdSeconds| and |kDnsTimedOutLowerThresholdSeconds|. |
| 171 | const int64 kDnsTimedOutLowerThresholdSeconds = |
| 172 | kDnsTimedOutThresholdSeconds - kSamplingIntervalMilliseconds / 1000; |
| 173 | string device_ip_address = device_->ipconfig()->properties().address; |
| 174 | vector<ConnectionInfo>::const_iterator it; |
| 175 | for (it = connection_infos.begin(); it != connection_infos.end(); ++it) { |
| 176 | if (it->protocol() != IPPROTO_UDP || |
| 177 | it->time_to_expire_seconds() > kDnsTimedOutThresholdSeconds || |
| 178 | it->time_to_expire_seconds() <= kDnsTimedOutLowerThresholdSeconds || |
| 179 | !it->is_unreplied() || |
| 180 | it->original_source_ip_address().ToString() != device_ip_address || |
| 181 | it->original_destination_port() != kDnsPort) |
| 182 | continue; |
| 183 | |
| 184 | ++accummulated_dns_failures_samples_; |
| 185 | SLOG(Link, 2) << __func__ |
| 186 | << ": DNS failures detected (" |
| 187 | << accummulated_dns_failures_samples_ << ")"; |
| 188 | return true; |
| 189 | } |
| 190 | } |
| 191 | ResetDnsFailingStatsWithLogging(); |
| 192 | return false; |
| 193 | } |
| 194 | |
| 195 | void TrafficMonitor::SampleTraffic() { |
| 196 | SLOG(Link, 3) << __func__; |
| 197 | |
| 198 | if (IsCongestedTxQueues() && |
| 199 | accummulated_congested_tx_queues_samples_ == |
| 200 | kMinimumFailedSamplesToTrigger) { |
| 201 | LOG(WARNING) << "Congested tx queues detected, out-of-credits?"; |
| 202 | outgoing_tcp_packets_not_routed_callback_.Run(); |
| 203 | } else if (IsDnsFailing() && |
| 204 | accummulated_dns_failures_samples_ == |
| 205 | kMinimumFailedSamplesToTrigger) { |
| 206 | LOG(WARNING) << "DNS queries failing, out-of-credits?"; |
| 207 | outgoing_tcp_packets_not_routed_callback_.Run(); |
| 208 | } |
| 209 | |
Ben Chan | b061f89 | 2013-02-27 17:46:55 -0800 | [diff] [blame] | 210 | dispatcher_->PostDelayedTask(sample_traffic_callback_.callback(), |
| 211 | kSamplingIntervalMilliseconds); |
| 212 | } |
| 213 | |
| 214 | } // namespace shill |