1 //
2 // Copyright (C) 2013 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/scan_session.h"
18 
19 #include <algorithm>
20 #include <set>
21 #include <string>
22 #include <vector>
23 
24 #include <base/bind.h>
25 #include <base/memory/weak_ptr.h>
26 #include <base/stl_util.h>
27 #include <base/strings/stringprintf.h>
28 
29 #include "shill/event_dispatcher.h"
30 #include "shill/logging.h"
31 #include "shill/metrics.h"
32 #include "shill/net/netlink_manager.h"
33 #include "shill/net/netlink_message.h"
34 #include "shill/net/nl80211_attribute.h"
35 #include "shill/net/nl80211_message.h"
36 
37 using base::Bind;
38 using base::StringPrintf;
39 using std::set;
40 using std::string;
41 using std::vector;
42 
43 namespace shill {
44 
45 namespace Logging {
46 static auto kModuleLogScope = ScopeLogger::kWiFi;
ObjectID(ScanSession * s)47 static string ObjectID(ScanSession* s) { return "(scan_session)"; }
48 }
49 
50 const float ScanSession::kAllFrequencies = 1.1;
51 const uint64_t ScanSession::kScanRetryDelayMilliseconds = 200;  // Arbitrary.
52 const size_t ScanSession::kScanRetryCount = 50;
53 
ScanSession(NetlinkManager * netlink_manager,EventDispatcher * dispatcher,const WiFiProvider::FrequencyCountList & previous_frequencies,const set<uint16_t> & available_frequencies,uint32_t ifindex,const FractionList & fractions,size_t min_frequencies,size_t max_frequencies,OnScanFailed on_scan_failed,Metrics * metrics)54 ScanSession::ScanSession(
55     NetlinkManager* netlink_manager,
56     EventDispatcher* dispatcher,
57     const WiFiProvider::FrequencyCountList& previous_frequencies,
58     const set<uint16_t>& available_frequencies,
59     uint32_t ifindex,
60     const FractionList& fractions,
61     size_t min_frequencies,
62     size_t max_frequencies,
63     OnScanFailed on_scan_failed,
64     Metrics* metrics)
65     : weak_ptr_factory_(this),
66       netlink_manager_(netlink_manager),
67       dispatcher_(dispatcher),
68       frequency_list_(previous_frequencies),
69       total_connections_(0),
70       total_connects_provided_(0),
71       total_fraction_wanted_(0.0),
72       wifi_interface_index_(ifindex),
73       ssids_(ByteString::IsLessThan),
74       fractions_(fractions),
75       min_frequencies_(min_frequencies),
76       max_frequencies_(max_frequencies),
77       on_scan_failed_(on_scan_failed),
78       scan_tries_left_(kScanRetryCount),
79       found_error_(false),
80       metrics_(metrics) {
81   sort(frequency_list_.begin(), frequency_list_.end(),
82        &ScanSession::CompareFrequencyCount);
83   // Add to |frequency_list_| all the frequencies from |available_frequencies|
84   // that aren't in |previous_frequencies|.
85   set<uint16_t> seen_frequencies;
86   for (const auto& freq_conn : frequency_list_) {
87     seen_frequencies.insert(freq_conn.frequency);
88     total_connections_ += freq_conn.connection_count;
89   }
90   for (const auto freq : available_frequencies) {
91     if (!ContainsKey(seen_frequencies, freq)) {
92       frequency_list_.push_back(WiFiProvider::FrequencyCount(freq, 0));
93     }
94   }
95 
96   SLOG(this, 6) << "Frequency connections vector:";
97   for (const auto& freq_conn : frequency_list_) {
98     SLOG(this, 6) << "    freq[" << freq_conn.frequency << "] = "
99                   << freq_conn.connection_count;
100   }
101 
102   original_frequency_count_ = frequency_list_.size();
103   ebusy_timer_.Pause();
104 }
105 
~ScanSession()106 ScanSession::~ScanSession() {
107   const int kLogLevel = 6;
108   ReportResults(kLogLevel);
109 }
110 
HasMoreFrequencies() const111 bool ScanSession::HasMoreFrequencies() const {
112   return !frequency_list_.empty();
113 }
114 
GetScanFrequencies(float fraction_wanted,size_t min_frequencies,size_t max_frequencies)115 vector<uint16_t> ScanSession::GetScanFrequencies(float fraction_wanted,
116                                                  size_t min_frequencies,
117                                                  size_t max_frequencies) {
118   DCHECK_GE(fraction_wanted, 0);
119   total_fraction_wanted_ += fraction_wanted;
120   float total_connects_wanted = total_fraction_wanted_ * total_connections_;
121 
122   vector<uint16_t> frequencies;
123   WiFiProvider::FrequencyCountList::iterator freq_connect =
124       frequency_list_.begin();
125   SLOG(this, 7) << "Scanning for frequencies:";
126   while (freq_connect != frequency_list_.end()) {
127     if (frequencies.size() >= min_frequencies) {
128       if (total_connects_provided_ >= total_connects_wanted)
129         break;
130       if (frequencies.size() >= max_frequencies)
131         break;
132     }
133     uint16_t frequency = freq_connect->frequency;
134     size_t connection_count = freq_connect->connection_count;
135     total_connects_provided_ += connection_count;
136     frequencies.push_back(frequency);
137     SLOG(this, 7) << "    freq[" << frequency << "] = " << connection_count;
138 
139     freq_connect = frequency_list_.erase(freq_connect);
140   }
141   return frequencies;
142 }
143 
InitiateScan()144 void ScanSession::InitiateScan() {
145   float fraction_wanted = kAllFrequencies;
146   if (!fractions_.empty()) {
147     fraction_wanted = fractions_.front();
148     fractions_.pop_front();
149   }
150   current_scan_frequencies_ = GetScanFrequencies(fraction_wanted,
151                                                  min_frequencies_,
152                                                  max_frequencies_);
153   DoScan(current_scan_frequencies_);
154 }
155 
ReInitiateScan()156 void ScanSession::ReInitiateScan() {
157   ebusy_timer_.Pause();
158   DoScan(current_scan_frequencies_);
159 }
160 
DoScan(const vector<uint16_t> & scan_frequencies)161 void ScanSession::DoScan(const vector<uint16_t>& scan_frequencies) {
162   if (scan_frequencies.empty()) {
163     LOG(INFO) << "Not sending empty frequency list";
164     return;
165   }
166   TriggerScanMessage trigger_scan;
167   trigger_scan.attributes()->CreateNl80211Attribute(
168       NL80211_ATTR_SCAN_FREQUENCIES, NetlinkMessage::MessageContext());
169   trigger_scan.attributes()->CreateNl80211Attribute(
170       NL80211_ATTR_SCAN_SSIDS, NetlinkMessage::MessageContext());
171   trigger_scan.attributes()->SetU32AttributeValue(NL80211_ATTR_IFINDEX,
172                                                   wifi_interface_index_);
173   AttributeListRefPtr frequency_list;
174   if (!trigger_scan.attributes()->GetNestedAttributeList(
175       NL80211_ATTR_SCAN_FREQUENCIES, &frequency_list) || !frequency_list) {
176     LOG(FATAL) << "Couldn't get NL80211_ATTR_SCAN_FREQUENCIES.";
177   }
178   trigger_scan.attributes()->SetNestedAttributeHasAValue(
179       NL80211_ATTR_SCAN_FREQUENCIES);
180 
181   SLOG(this, 6) << "We have requested scan frequencies:";
182   string attribute_name;
183   int i = 0;
184   for (const auto freq : scan_frequencies) {
185     SLOG(this, 6) << "  " << freq;
186     attribute_name = StringPrintf("Frequency-%d", i);
187     frequency_list->CreateU32Attribute(i, attribute_name.c_str());
188     frequency_list->SetU32AttributeValue(i, freq);
189     ++i;
190   }
191 
192   if (!ssids_.empty()) {
193     AttributeListRefPtr ssid_list;
194     if (!trigger_scan.attributes()->GetNestedAttributeList(
195         NL80211_ATTR_SCAN_SSIDS, &ssid_list) || !ssid_list) {
196       LOG(FATAL) << "Couldn't get NL80211_ATTR_SCAN_SSIDS attribute.";
197     }
198     trigger_scan.attributes()->SetNestedAttributeHasAValue(
199         NL80211_ATTR_SCAN_SSIDS);
200     int i = 0;
201     string attribute_name;
202     for (const auto& ssid : ssids_) {
203       attribute_name = StringPrintf("NL80211_ATTR_SSID_%d", i);
204       ssid_list->CreateRawAttribute(i, attribute_name.c_str());
205       ssid_list->SetRawAttributeValue(i, ssid);
206       ++i;
207     }
208     // Add an empty one at the end so we ask for a broadcast in addition to
209     // the specific SSIDs.
210     attribute_name = StringPrintf("NL80211_ATTR_SSID_%d", i);
211     ssid_list->CreateRawAttribute(i, attribute_name.c_str());
212     ssid_list->SetRawAttributeValue(i, ByteString());
213   }
214   netlink_manager_->SendNl80211Message(
215       &trigger_scan,
216       Bind(&ScanSession::OnTriggerScanResponse,
217            weak_ptr_factory_.GetWeakPtr()),
218       Bind(&NetlinkManager::OnAckDoNothing),
219       Bind(&ScanSession::OnTriggerScanErrorResponse,
220            weak_ptr_factory_.GetWeakPtr()));
221 }
222 
OnTriggerScanResponse(const Nl80211Message & netlink_message)223 void ScanSession::OnTriggerScanResponse(const Nl80211Message& netlink_message) {
224   LOG(WARNING) << "Didn't expect _this_ netlink message, here:";
225   netlink_message.Print(0, 0);
226   on_scan_failed_.Run();
227   return;
228 }
229 
OnTriggerScanErrorResponse(NetlinkManager::AuxilliaryMessageType type,const NetlinkMessage * netlink_message)230 void ScanSession::OnTriggerScanErrorResponse(
231     NetlinkManager::AuxilliaryMessageType type,
232     const NetlinkMessage* netlink_message) {
233   switch (type) {
234     case NetlinkManager::kErrorFromKernel: {
235         if (!netlink_message) {
236           LOG(ERROR) << __func__ << ": Message failed: NetlinkManager Error.";
237           found_error_ = true;
238           on_scan_failed_.Run();
239           break;
240         }
241         if (netlink_message->message_type() !=
242             ErrorAckMessage::GetMessageType()) {
243           LOG(ERROR) << __func__ << ": Message failed: Not an error.";
244           found_error_ = true;
245           on_scan_failed_.Run();
246           break;
247         }
248         const ErrorAckMessage* error_ack_message =
249             static_cast<const ErrorAckMessage*>(netlink_message);
250         if (error_ack_message->error()) {
251           LOG(ERROR) << __func__ << ": Message failed: "
252                      << error_ack_message->ToString();
253           if (error_ack_message->error() == EBUSY) {
254             if (scan_tries_left_ == 0) {
255               LOG(ERROR) << "Retried progressive scan " << kScanRetryCount
256                          << " times and failed each time.  Giving up.";
257               found_error_ = true;
258               on_scan_failed_.Run();
259               scan_tries_left_ = kScanRetryCount;
260               return;
261             }
262             --scan_tries_left_;
263             SLOG(this, 3) << __func__ << " - trying again (" << scan_tries_left_
264                           << " remaining after this)";
265             ebusy_timer_.Resume();
266             dispatcher_->PostDelayedTask(Bind(&ScanSession::ReInitiateScan,
267                                               weak_ptr_factory_.GetWeakPtr()),
268                                          kScanRetryDelayMilliseconds);
269             break;
270           }
271           found_error_ = true;
272           on_scan_failed_.Run();
273         } else {
274           SLOG(this, 6) << __func__ << ": Message ACKed";
275         }
276       }
277       break;
278 
279     case NetlinkManager::kUnexpectedResponseType:
280       LOG(ERROR) << "Message not handled by regular message handler:";
281       if (netlink_message) {
282         netlink_message->Print(0, 0);
283       }
284       found_error_ = true;
285       on_scan_failed_.Run();
286       break;
287 
288     case NetlinkManager::kTimeoutWaitingForResponse:
289       // This is actually expected since, in the working case, a trigger scan
290       // message gets its responses broadcast rather than unicast.
291       break;
292 
293     default:
294       LOG(ERROR) << "Unexpected auxiliary message type: " << type;
295       found_error_ = true;
296       on_scan_failed_.Run();
297       break;
298   }
299 }
300 
ReportResults(int log_level)301 void ScanSession::ReportResults(int log_level) {
302   SLOG(this, log_level) << "------ ScanSession finished ------";
303   SLOG(this, log_level) << "Scanned "
304                         << original_frequency_count_ - frequency_list_.size()
305                         << " frequencies (" << frequency_list_.size()
306                         << " remaining)";
307   if (found_error_) {
308     SLOG(this, log_level) << "ERROR encountered during scan ("
309                           << current_scan_frequencies_.size() << " frequencies"
310                           << " dangling - counted as scanned but, really, not)";
311   } else {
312     SLOG(this, log_level) << "No error encountered during scan.";
313   }
314 
315   base::TimeDelta elapsed_time;
316   ebusy_timer_.GetElapsedTime(&elapsed_time);
317   if (metrics_) {
318     metrics_->SendToUMA(Metrics::kMetricWiFiScanTimeInEbusyMilliseconds,
319                         elapsed_time.InMilliseconds(),
320                         Metrics::kMetricTimeToScanMillisecondsMin,
321                         Metrics::kMetricTimeToScanMillisecondsMax,
322                         Metrics::kMetricTimeToScanMillisecondsNumBuckets);
323   }
324   SLOG(this, log_level) << "Spent " << elapsed_time.InMillisecondsRoundedUp()
325                         << " milliseconds waiting for EBUSY.";
326 }
327 
AddSsid(const ByteString & ssid)328 void ScanSession::AddSsid(const ByteString& ssid) {
329   ssids_.insert(ssid);
330 }
331 
332 // static
CompareFrequencyCount(const WiFiProvider::FrequencyCount & first,const WiFiProvider::FrequencyCount & second)333 bool ScanSession::CompareFrequencyCount(
334     const WiFiProvider::FrequencyCount& first,
335     const WiFiProvider::FrequencyCount& second) {
336   return first.connection_count > second.connection_count;
337 }
338 
339 }  // namespace shill
340 
341