1 //
2 // Copyright (C) 2014 The Android Open Source Project
3 //
4 // Licensed under the Apache License, Version 2.0 (the "License");
5 // you may not use this file except in compliance with the License.
6 // You may obtain a copy of the License at
7 //
8 //      http://www.apache.org/licenses/LICENSE-2.0
9 //
10 // Unless required by applicable law or agreed to in writing, software
11 // distributed under the License is distributed on an "AS IS" BASIS,
12 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 // See the License for the specific language governing permissions and
14 // limitations under the License.
15 //
16 
17 #include "shill/wifi/mac80211_monitor.h"
18 
19 #include <algorithm>
20 
21 #include <base/files/file_util.h>
22 #include <base/strings/string_number_conversions.h>
23 #include <base/strings/string_split.h>
24 #include <base/strings/stringprintf.h>
25 
26 #include "shill/logging.h"
27 #include "shill/metrics.h"
28 #include "shill/net/shill_time.h"
29 
30 namespace shill {
31 
32 using std::string;
33 using std::vector;
34 
35 namespace Logging {
36 static auto kModuleLogScope = ScopeLogger::kWiFi;
ObjectID(Mac80211Monitor * m)37 static string ObjectID(Mac80211Monitor* m) { return m->link_name(); }
38 }
39 
40 // statics
41 // At 17-25 bytes per queue, this accommodates 80 queues.
42 // ath9k has 4 queues, and WP2 has 16 queues.
43 const size_t Mac80211Monitor::kMaxQueueStateSizeBytes = 2048;
44 const char Mac80211Monitor::kQueueStatusPathFormat[] =
45     "/sys/kernel/debug/ieee80211/%s/queues";
46 const char Mac80211Monitor::kWakeQueuesPathFormat[] =
47     "/sys/kernel/debug/ieee80211/%s/wake_queues";
48 const time_t Mac80211Monitor::kQueueStatePollIntervalSeconds = 30;
49 const time_t Mac80211Monitor::kMinimumTimeBetweenWakesSeconds = 60;
50 
Mac80211Monitor(EventDispatcher * dispatcher,const string & link_name,size_t queue_length_limit,const base::Closure & on_repair_callback,Metrics * metrics)51 Mac80211Monitor::Mac80211Monitor(
52     EventDispatcher* dispatcher,
53     const string& link_name,
54     size_t queue_length_limit,
55     const base::Closure& on_repair_callback,
56     Metrics* metrics)
57     : time_(Time::GetInstance()),
58       dispatcher_(dispatcher),
59       link_name_(link_name),
60       queue_length_limit_(queue_length_limit),
61       on_repair_callback_(on_repair_callback),
62       metrics_(metrics),
63       phy_name_("phy-unknown"),
64       last_woke_queues_monotonic_seconds_(0),
65       is_running_(false),
66       have_ever_read_queue_state_file_(false),
67       is_device_connected_(false),
68       weak_ptr_factory_(this) {
69   CHECK(time_);
70   CHECK(dispatcher_);
71   CHECK(metrics_);
72 }
73 
~Mac80211Monitor()74 Mac80211Monitor::~Mac80211Monitor() {
75   Stop();
76 }
77 
Start(const string & phy_name)78 void Mac80211Monitor::Start(const string& phy_name) {
79   SLOG(this, 2) << __func__ << " on " << link_name_ << " (" << phy_name << ")";
80   CHECK(!is_running_);
81   phy_name_ = phy_name;
82   queue_state_file_path_ = base::FilePath(
83       base::StringPrintf(kQueueStatusPathFormat, phy_name.c_str()));
84   wake_queues_file_path_ = base::FilePath(
85       base::StringPrintf(kWakeQueuesPathFormat, phy_name.c_str()));
86   last_woke_queues_monotonic_seconds_ = 0;
87   StartTimer();
88   is_running_ = true;
89 }
90 
Stop()91 void Mac80211Monitor::Stop() {
92   SLOG(this, 2) << __func__ << " on " << link_name_ << " (" << phy_name_ << ")";
93   StopTimer();
94   is_running_ = false;
95 }
96 
UpdateConnectedState(bool new_state)97 void Mac80211Monitor::UpdateConnectedState(bool new_state) {
98   SLOG(this, 2) << __func__ << " (new_state=" << new_state << ")";
99   is_device_connected_ = new_state;
100 }
101 
StartTimer()102 void Mac80211Monitor::StartTimer() {
103   SLOG(this, 2) << __func__;
104   if (check_queues_callback_.IsCancelled()) {
105     check_queues_callback_.Reset(
106         Bind(&Mac80211Monitor::WakeQueuesIfNeeded,
107              weak_ptr_factory_.GetWeakPtr()));
108   }
109   dispatcher_->PostDelayedTask(check_queues_callback_.callback(),
110                                 kQueueStatePollIntervalSeconds * 1000);
111 }
112 
StopTimer()113 void Mac80211Monitor::StopTimer() {
114   SLOG(this, 2) << __func__;
115   check_queues_callback_.Cancel();
116 }
117 
WakeQueuesIfNeeded()118 void Mac80211Monitor::WakeQueuesIfNeeded() {
119   SLOG(this, 2) << __func__ << " on " << link_name_ << " (" << phy_name_ << ")";
120   CHECK(is_running_);
121   StartTimer();  // Always re-arm timer.
122 
123   if (is_device_connected_) {
124     SLOG(this, 5) << "Skipping queue check: device is connected.";
125     return;
126   }
127 
128   string queue_state_string;
129   if (!base::ReadFileToString(queue_state_file_path_, &queue_state_string,
130                               kMaxQueueStateSizeBytes)) {
131     if (have_ever_read_queue_state_file_) {
132       LOG(WARNING) << __func__ << ": incomplete read on "
133                    << queue_state_file_path_.value();
134     }
135     return;
136   }
137   have_ever_read_queue_state_file_ = true;
138 
139   uint32_t stuck_flags =
140       CheckAreQueuesStuck(ParseQueueState(queue_state_string));
141   SLOG(this, 2) << __func__ << " stuck_flags=" << stuck_flags;
142   if (!(stuck_flags & kStopFlagPowerSave)) {
143     if (stuck_flags) {
144       LOG(INFO) << "Skipping wake: stuck_flags is "
145                 << std::showbase << std::hex << stuck_flags
146                 << " (require " << kStopFlagPowerSave << " to wake)."
147                 << std::dec << std::noshowbase;
148     }
149     return;
150   }
151 
152   time_t now_monotonic_seconds = 0;
153   if (!time_->GetSecondsMonotonic(&now_monotonic_seconds)) {
154     LOG(WARNING) << "Skipping reset: failed to get monotonic time";
155     return;
156   }
157 
158   time_t elapsed = now_monotonic_seconds - last_woke_queues_monotonic_seconds_;
159   if (elapsed < kMinimumTimeBetweenWakesSeconds) {
160     LOG(WARNING) << "Skipping reset "
161                  << "(min interval=" << kMinimumTimeBetweenWakesSeconds
162                  << ", elapsed=" << elapsed << ")";
163     return;
164   }
165 
166   LOG(WARNING) << "Queues appear stuck; waking.";
167   if (base::WriteFile(wake_queues_file_path_, "", sizeof("")) < 0) {
168     PLOG(ERROR) << "Failed to write to " << wake_queues_file_path_.value();
169     return;
170   }
171 
172   if (!on_repair_callback_.is_null()) {
173     on_repair_callback_.Run();
174   }
175 
176   last_woke_queues_monotonic_seconds_ = now_monotonic_seconds;
177 }
178 
CheckAreQueuesStuck(const vector<QueueState> & queue_states)179 uint32_t Mac80211Monitor::CheckAreQueuesStuck(
180     const vector<QueueState>& queue_states) {
181   size_t max_stuck_queue_len = 0;
182   uint32_t stuck_flags = 0;
183   for (const auto& queue_state : queue_states) {
184     if (queue_state.queue_length < queue_length_limit_) {
185       SLOG(this, 5) << __func__
186                     << " skipping queue of length " << queue_state.queue_length
187                     << " (threshold is " << queue_length_limit_ << ")";
188       continue;
189     }
190     if (!queue_state.stop_flags) {
191       SLOG(this, 5) << __func__
192                     << " skipping queue of length " << queue_state.queue_length
193                     << " (not stopped)";
194       continue;
195     }
196     stuck_flags = stuck_flags | queue_state.stop_flags;
197     max_stuck_queue_len =
198         std::max(max_stuck_queue_len, queue_state.queue_length);
199   }
200 
201   if (max_stuck_queue_len >= queue_length_limit_) {
202     LOG(WARNING) << "max queue length is " << max_stuck_queue_len;
203   }
204 
205   if (stuck_flags) {
206     for (unsigned int i = 0; i < kStopReasonMax; ++i) {
207       auto stop_reason = static_cast<QueueStopReason>(i);
208       if (stuck_flags & GetFlagForReason(stop_reason)) {
209         metrics_->SendEnumToUMA(Metrics::kMetricWifiStoppedTxQueueReason,
210                                 stop_reason,
211                                 kStopReasonMax);
212       }
213     }
214 
215     metrics_->SendToUMA(Metrics::kMetricWifiStoppedTxQueueLength,
216                         max_stuck_queue_len,
217                         Metrics::kMetricWifiStoppedTxQueueLengthMin,
218                         Metrics::kMetricWifiStoppedTxQueueLengthMax,
219                         Metrics::kMetricWifiStoppedTxQueueLengthNumBuckets);
220   }
221 
222   return stuck_flags;
223 }
224 
225 // example input:
226 // 01: 0x00000000/0
227 // ...
228 // 04: 0x00000000/0
229 //
230 // static
231 vector<Mac80211Monitor::QueueState>
ParseQueueState(const string & state_string)232 Mac80211Monitor::ParseQueueState(const string& state_string) {
233   vector<QueueState> queue_states;
234   vector<string> queue_state_strings = base::SplitString(
235       state_string, "\n", base::TRIM_WHITESPACE, base::SPLIT_WANT_ALL);
236 
237   if (queue_state_strings.empty()) {
238     return queue_states;
239   }
240 
241   // Trailing newline generates empty string as last element.
242   // Discard that empty string if present.
243   if (queue_state_strings.back().empty()) {
244     queue_state_strings.pop_back();
245   }
246 
247   for (const auto& queue_state : queue_state_strings) {
248     // Example |queue_state|: "00: 0x00000000/10".
249     vector<string> queuenum_and_state = base::SplitString(
250         queue_state, ":", base::TRIM_WHITESPACE, base::SPLIT_WANT_ALL);
251     if (queuenum_and_state.size() != 2) {
252       LOG(WARNING) << __func__ << ": parse error on " << queue_state;
253       continue;
254     }
255 
256     // Example |queuenum_and_state|: {"00", "0x00000000/10"}.
257     vector<string> stopflags_and_length = base::SplitString(
258         queuenum_and_state[1], "/", base::TRIM_WHITESPACE,
259         base::SPLIT_WANT_ALL);
260     if (stopflags_and_length.size() != 2) {
261       LOG(WARNING) << __func__ << ": parse error on " << queue_state;
262       continue;
263     }
264 
265     // Example |stopflags_and_length|: {"0x00000000", "10"}.
266     size_t queue_number;
267     uint32_t stop_flags;
268     size_t queue_length;
269     if (!base::StringToSizeT(queuenum_and_state[0], &queue_number)) {
270       LOG(WARNING) << __func__ << ": parse error on " << queue_state;
271       continue;
272     }
273     if (!base::HexStringToUInt(stopflags_and_length[0], &stop_flags)) {
274       LOG(WARNING) << __func__ << ": parse error on " << queue_state;
275       continue;
276     }
277     if (!base::StringToSizeT(stopflags_and_length[1], &queue_length)) {
278       LOG(WARNING) << __func__ << ": parse error on " << queue_state;
279       continue;
280     }
281     queue_states.emplace_back(queue_number, stop_flags, queue_length);
282   }
283 
284   return queue_states;
285 }
286 
287 // static
GetFlagForReason(QueueStopReason reason)288 Mac80211Monitor::QueueStopFlag Mac80211Monitor::GetFlagForReason(
289     QueueStopReason reason) {
290   switch (reason) {
291     case kStopReasonDriver:
292       return kStopFlagDriver;
293     case kStopReasonPowerSave:
294       return kStopFlagPowerSave;
295     case kStopReasonChannelSwitch:
296       return kStopFlagChannelSwitch;
297     case kStopReasonAggregation:
298       return kStopFlagAggregation;
299     case kStopReasonSuspend:
300       return kStopFlagSuspend;
301     case kStopReasonBufferAdd:
302       return kStopFlagBufferAdd;
303     case kStopReasonChannelTypeChange:
304       return kStopFlagChannelTypeChange;
305   }
306 
307   // The switch statement above is exhaustive (-Wswitch will complain
308   // if it is not). But |reason| might be outside the defined range for
309   // the enum, so we need this to keep the compiler happy.
310   return kStopFlagInvalid;
311 }
312 
313 }  // namespace shill
314