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
30namespace shill {
31
32using std::string;
33using std::vector;
34
35namespace Logging {
36static auto kModuleLogScope = ScopeLogger::kWiFi;
37static 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.
43const size_t Mac80211Monitor::kMaxQueueStateSizeBytes = 2048;
44const char Mac80211Monitor::kQueueStatusPathFormat[] =
45    "/sys/kernel/debug/ieee80211/%s/queues";
46const char Mac80211Monitor::kWakeQueuesPathFormat[] =
47    "/sys/kernel/debug/ieee80211/%s/wake_queues";
48const time_t Mac80211Monitor::kQueueStatePollIntervalSeconds = 30;
49const time_t Mac80211Monitor::kMinimumTimeBetweenWakesSeconds = 60;
50
51Mac80211Monitor::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
74Mac80211Monitor::~Mac80211Monitor() {
75  Stop();
76}
77
78void 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
91void Mac80211Monitor::Stop() {
92  SLOG(this, 2) << __func__ << " on " << link_name_ << " (" << phy_name_ << ")";
93  StopTimer();
94  is_running_ = false;
95}
96
97void Mac80211Monitor::UpdateConnectedState(bool new_state) {
98  SLOG(this, 2) << __func__ << " (new_state=" << new_state << ")";
99  is_device_connected_ = new_state;
100}
101
102void 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
113void Mac80211Monitor::StopTimer() {
114  SLOG(this, 2) << __func__;
115  check_queues_callback_.Cancel();
116}
117
118void 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
179uint32_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
231vector<Mac80211Monitor::QueueState>
232Mac80211Monitor::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
288Mac80211Monitor::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