$search
00001 import radio 00002 import time 00003 import state_publisher 00004 import config 00005 from twisted.internet import reactor 00006 import mac_addr 00007 import event 00008 import multiset 00009 from twisted.internet.defer import inlineCallbacks 00010 import async_helpers 00011 import random 00012 import logging_config 00013 00014 scan_periods_log = logging_config.get_logger_stream_for_file('scan_periods') 00015 known_bsses_log = logging_config.get_logger_stream_for_file('known_bsses') 00016 radio_manager_decisions = logging_config.get_logger_stream_for_file('console.radio_manager_decisions') 00017 00018 def check_band(freq, bands): 00019 if freq < 3000 and bands & 1: 00020 return True 00021 if freq > 4000 and bands & 2: 00022 return True 00023 return False 00024 00025 class Frequency: 00026 def __init__(self, freq, period): 00027 self.frequency = freq 00028 self.period = period 00029 self.next_scan_time_by_iface = {} 00030 self.next_scan_time = 0 00031 self.do_not_retry_before = {} 00032 self.interfaces = multiset.Multiset() 00033 self.last_hit = 0 00034 00035 def update_next_scan_time(self, iface, when): 00036 self.next_scan_time = when 00037 self.next_scan_time_by_iface[iface] = when 00038 00039 def set_period(self, period): 00040 when = time.time() + period 00041 self.period = period 00042 self.next_scan_time = min(self.next_scan_time, when) 00043 for iface in self.next_scan_time_by_iface: 00044 self.next_scan_time_by_iface[iface] = min(self.next_scan_time_by_iface[iface], when) 00045 00046 class NoFrequenciesReady(Exception): 00047 def __init__(self, next_time): 00048 Exception.__init__(self) 00049 self.next_time = next_time 00050 00051 class FrequencyList: 00052 def __init__(self): 00053 self.frequencies = {} 00054 self.bands = 0 00055 self.scan_period_cold = config.get_parameter('scan_period_cold', 10) 00056 self.scan_reschedule_delay = config.get_parameter('scan_reschedule_delay', 2) 00057 self.scan_period_randomness = config.get_parameter('scan_period_randomness', 0) 00058 self.min_scan_interval = config.get_parameter('min_scan_interval', 1) 00059 00060 def add(self, freq, iface): 00061 if freq not in self.frequencies: 00062 self.frequencies[freq] = Frequency(freq, self.scan_period_cold) 00063 self.frequencies[freq].interfaces.add(iface) 00064 00065 def remove(self, freq, iface): 00066 self.frequencies[freq].interfaces.remove(iface) 00067 00068 def next_scan_freq(self, iface, now = None, allow_early = False): 00069 if now == None: 00070 now = time.time() 00071 00072 # Which frequencies can we consider? 00073 active_freqs = filter(lambda f: iface in f.interfaces and check_band(f.frequency, self.bands), self.frequencies.itervalues()) 00074 00075 # Pick the frequency with the next expiry time. 00076 try: 00077 freq = min(active_freqs, key = lambda f: f.next_scan_time) 00078 except ValueError: # No active frequencies 00079 raise NoFrequenciesReady(None) 00080 00081 # If no frequency has expired, take into account when it was last seen by this interface. 00082 if freq.next_scan_time > now: 00083 #print "Pondering frequencies that have not been updated recently on ", iface.iface 00084 freq = min(active_freqs, key = lambda f: f.next_scan_time_by_iface.get(iface,0)) 00085 00086 earliest_scan_time = freq.do_not_retry_before.get(iface, 0) 00087 if not allow_early: 00088 earliest_scan_time = max(earliest_scan_time, freq.next_scan_time) 00089 if earliest_scan_time > now: 00090 raise NoFrequenciesReady(earliest_scan_time) 00091 rand_period = freq.period * (0.5 + self.scan_period_randomness * random.random()) 00092 freq.update_next_scan_time(iface, now + rand_period) 00093 freq.do_not_retry_before[iface] = now + self.min_scan_interval 00094 return freq.frequency 00095 00096 def next_scan_freqs(self, iface, count, allow_early = False): 00097 now = time.time() 00098 freqs = [] 00099 for i in range(count): 00100 try: 00101 f = self.next_scan_freq(iface, now, allow_early) 00102 except NoFrequenciesReady, nfr: 00103 if freqs: 00104 break 00105 raise 00106 freqs.append(f) 00107 return freqs 00108 00109 def set_freq_period(self, freq, period): 00110 f = self.frequencies[freq] 00111 f.set_period(period) 00112 00113 def reschedule(self, iface, freqs): 00114 when = time.time() + self.scan_reschedule_delay 00115 for f in freqs: 00116 self.frequencies[f].update_next_scan_time(iface, when) 00117 00118 def hit(self, freq, stamp): 00119 """Called each time a bss is seen.""" 00120 try: 00121 self.frequencies[freq].last_hit = max(self.frequencies[freq].last_hit, stamp) 00122 except KeyError: 00123 print "Got a scan on an unexpected frequency." # FIXME 00124 pass # We got a hit on a frequency that we aren't scanning for. Strange. 00125 00126 def make_id(bss): 00127 return (bss.ssid, bss.bssid) 00128 00129 class Bss: 00130 def __init__(self, bss): 00131 self.id = make_id(bss) 00132 self.ssid = bss.ssid 00133 self.bssid = bss.bssid 00134 self.by_iface = {} 00135 self.frequency = bss.frequency 00136 00137 def update(self, bss, iface): 00138 assert bss.ssid == self.ssid 00139 assert bss.bssid == self.bssid 00140 if self.frequency != bss.frequency: 00141 print "Frequency for bss %s, %s has changed from %i to %i MHz."%(mac_addr.pretty(bss.bssid), bss.ssid, self.frequency, bss.frequency) # FIXME 00142 self.frequency = bss.frequency 00143 self.by_iface[iface] = bss 00144 00145 def last_seen(self, iface = None): 00146 if iface is None: 00147 return max(bss.stamp.to_sec() for bss in self.by_iface.itervalues()) 00148 if iface in self.by_iface: 00149 return self.by_iface[iface].stamp.to_sec() 00150 else: 00151 return 0 00152 00153 class BssList: 00154 def __init__(self, freq_list): 00155 self.bsses = {} 00156 self.freq_list = freq_list 00157 pass 00158 00159 def update(self, bsses, iface): 00160 for bss in bsses: 00161 id = (bss.ssid, bss.bssid) 00162 if id not in self.bsses: 00163 self.bsses[id] = Bss(bss) 00164 self.bsses[id].update(bss, iface) 00165 self.freq_list.hit(bss.frequency, bss.stamp.to_sec()) 00166 00167 if True: # Gives an overview of currently known bsses. 00168 all = self.bsses.items() 00169 all.sort(key=lambda (x,y):(y.frequency, x)) 00170 now = time.time() 00171 print >> known_bsses_log, "\033[2J\033[0;0H" 00172 print >> known_bsses_log, "Known BSSes bsses:" 00173 for _, bss in all: 00174 print >> known_bsses_log, mac_addr.pretty(bss.bssid), "%20.20s"%bss.ssid, bss.frequency, 00175 ifaces = bss.by_iface.keys() 00176 ifaces.sort() 00177 min_stamp = now - max(bss.by_iface.itervalues(), key = lambda bss: bss.stamp).stamp.to_sec() 00178 max_level = max(bss.by_iface.itervalues(), key = lambda bss: bss.level).level 00179 print >> known_bsses_log, "%5.1f/%3i"%(min_stamp,max_level), 00180 for iface in ifaces: 00181 print >> known_bsses_log, iface.iface, "%5.1f/%3i"%(now - bss.by_iface[iface].stamp.to_sec(), bss.by_iface[iface].level), 00182 print >> known_bsses_log 00183 print >> known_bsses_log 00184 00185 fl = self.freq_list.frequencies.keys() 00186 fl.sort() 00187 for f in fl: 00188 fc = self.freq_list.frequencies[f] 00189 if fc.last_hit: 00190 print >> known_bsses_log, f, "%5.1f"%(now - fc.last_hit), 00191 else: 00192 print >> known_bsses_log, f, "never", 00193 print >> known_bsses_log, "%5.1f"%(fc.next_scan_time - now), 00194 for iface in fc.next_scan_time_by_iface: 00195 print >> known_bsses_log, "%s %5.1f"%(iface.iface, now - fc.next_scan_time_by_iface[iface]), 00196 print >> known_bsses_log 00197 print >> known_bsses_log 00198 00199 class ScanManager: 00200 def __init__(self): 00201 self.failed_scan_delay = config.get_parameter('failed_scan_delay', 1) 00202 self.scan_results = {} 00203 self.frequencies = FrequencyList() 00204 self.num_scan_frequencies = config.get_parameter('num_scan_frequencies', 4) 00205 self.scheduled_scan = {} 00206 self.bss_list = BssList(self.frequencies) 00207 self.new_scan_data = event.Event() 00208 00209 def add_iface(self, iface): 00210 # Subscribe to state changes that might cause us to trigger a scan. 00211 iface.radio_sm.scanning.subscribe(self._scanning_state_cb, iface) 00212 iface.radio_sm.associated.subscribe(self._scanning_state_cb, iface) 00213 iface.radio_sm.associated.subscribe(self._log_associations, iface) 00214 iface.radio_sm.scanning_enabled.subscribe(self._scanning_state_cb, iface) 00215 00216 # Subscribe to scan results 00217 iface.radio_sm.scan_results_event.subscribe_repeating(self._scan_event_cb, iface) 00218 # Subscribe to changes in frequency list 00219 iface.radio_sm.frequency_list.subscribe(self._frequency_list_cb, iface) 00220 00221 def _scanning_state_cb(self, iface, old_state, new_state): 00222 """A state change that might cause us to start scanning has occurred.""" 00223 self._trigger_scan(iface) 00224 00225 def _log_associations(self, iface, old_state, new_state): 00226 if new_state: 00227 print >> radio_manager_decisions, "--> Associated to %s on %s."%(mac_addr.pretty(new_state.bssid), iface.iface) 00228 elif new_state == radio.Associating: 00229 print >> radio_manager_decisions, "--> Associating on %s."%iface.iface 00230 elif new_state == radio.Unassociated: 00231 print >> radio_manager_decisions, "--> Unassociated on %s."%iface.iface 00232 else: 00233 print >> radio_manager_decisions, "--> ERROR!! Unknown association state %s on %s."%(new_state, iface.iface) 00234 00235 @inlineCallbacks 00236 def _trigger_scan(self, iface): 00237 #if iface.radio_sm.associated.get(): 00238 # async_helpers.async_sleep(0.1) 00239 #print "_trigger_scan", iface.iface 00240 if iface in self.scheduled_scan: 00241 if self.scheduled_scan[iface].active(): 00242 self.scheduled_scan[iface].cancel() 00243 del self.scheduled_scan[iface] 00244 if not iface.radio_sm.scanning_enabled.get() or iface.radio_sm.scanning.get(): 00245 #print "_trigger_scan bailing", iface.radio_sm.scanning_enabled.get(), iface.radio_sm.scanning.get() 00246 return # We are not in a scanning state, or we are currently scanning. 00247 try: 00248 #print "_trigger_scan association", iface.radio_sm.associated.get(), not iface.radio_sm.associated.get() 00249 #if iface.radio_sm.associated.get(): 00250 # return # FIXME Take this out once associated scanning works well. 00251 if iface.radio_sm.associated.get(): 00252 freqs = self.frequencies.next_scan_freqs(iface, 1, False) 00253 else: 00254 freqs = self.frequencies.next_scan_freqs(iface, self.num_scan_frequencies, True) 00255 except NoFrequenciesReady, nfr: 00256 if nfr.next_time: 00257 self.scheduled_scan[iface] = reactor.callLater(max(0.1, nfr.next_time - time.time()), self._trigger_scan, iface) 00258 #print "No frequencies for ", iface.iface, nfr.next_time - time.time() 00259 #else: 00260 #print "No frequencies for", iface.iface 00261 else: 00262 print "Triggering scan", iface.iface, freqs 00263 rslt = yield iface.radio_sm.scan(freqs) 00264 if not rslt: 00265 print "Scan failed", iface.iface, freqs 00266 yield async_helpers.async_sleep(self.failed_scan_delay) 00267 self.frequencies.reschedule(iface, freqs) 00268 00269 def _scan_event_cb(self, iface, bsses): 00270 #print "_scan_event_cb", len(bsses) 00271 self.bss_list.update(bsses, iface) 00272 self.new_scan_data.trigger() 00273 00274 def _frequency_list_cb(self, iface, old_state, new_state): 00275 now = time.time() 00276 for f in new_state: 00277 self.frequencies.add(f, iface) 00278 00279 if old_state != state_publisher.JustSubscribed: 00280 for f in old_state: 00281 self.frequencies.remove(f, iface) 00282 00283 self._trigger_scan(iface) 00284 00285 class RadioManager: 00286 def __init__(self): 00287 self.scan_manager = ScanManager() 00288 self.best_active = None 00289 self.iface_associations = {} 00290 self.initial_inhibit_end = time.time() + config.get_parameter('initial_assoc_inhibit', 5) 00291 self.bss_expiry_time = config.get_parameter('bss_expiry_time', 5) 00292 self.activate_hysteresis = config.get_parameter('activate_hysteresis', 5) 00293 self.max_hot_frequencies = config.get_parameter('max_hot_frequencies', 3) 00294 self.scan_period_warm = config.get_parameter('scan_period_warm', 10) 00295 self.scan_period_hot = config.get_parameter('scan_period_hot', 4) 00296 self.reassociate_hysteresis = config.get_parameter('reassociate_hysteresis', 5) 00297 self.same_bss_penalty = config.get_parameter('same_bss_penalty', 20) 00298 self.interfaces = set() 00299 00300 self.set_mode() # Initializes some variables 00301 00302 self.scan_manager.new_scan_data.subscribe_repeating(self._new_scan_data) 00303 self.hot_bss_expiry_time = config.get_parameter('hot_bss_expiry_time', 5) 00304 self.warm_bss_expiry_time = config.get_parameter('warm_bss_expiry_time', 3 * self.scan_period_warm) 00305 00306 def add_iface(self, iface): 00307 self.scan_manager.add_iface(iface) 00308 self.interfaces.add(iface) 00309 iface.radio_sm.associated.subscribe(self._associated_cb, iface) 00310 iface.dhcpdata.error_event.subscribe_repeating(self._dhcp_fail, iface) 00311 00312 def set_mode(self, ssid="", bssid="", band=0, scan_only=False, iface = ""): 00313 self.scan_only = scan_only 00314 self.forced_ssid = ssid 00315 self.forced_bssid = bssid 00316 self.forced_band = band 00317 self.forced_iface = iface 00318 self.scan_manager.frequencies.bands = band 00319 for iface in self.interfaces: 00320 self._check_cur_bss(iface) 00321 self.scan_manager._trigger_scan(iface) # In case there were no frequencies before. 00322 00323 def _associated_cb(self, iface, old_state, new_state): 00324 if new_state == radio.Unassociated: 00325 if iface in self.iface_associations: 00326 del self.iface_associations[iface] 00327 self._check_cur_bss(iface) 00328 00329 def _check_cur_bss(self, iface): 00330 """Makes sure that the current bss satisfies forcing constraints.""" 00331 #print "_check_cur_bss" 00332 cur_bss = iface.radio_sm.associated.get() 00333 if not cur_bss: 00334 return 00335 if not self.check_bss_matches_forcing(cur_bss): 00336 print iface.iface, "associated to", cur_bss.ssid, mac_addr.pretty(cur_bss.bssid), cur_bss.frequency 00337 print "but want", self.forced_ssid, self.forced_ssid, self.forced_band 00338 print "Unassociating because bss does not match requirements." 00339 iface.radio_sm.unassociate() 00340 return 00341 if not self.check_iface_matches_forcing(iface): 00342 print "Unassociating %s because interface forced to %s"%(iface, self.forced_iface) 00343 iface.radio_sm.unassociate() 00344 return 00345 00346 def check_bss_matches_forcing(self, bss): 00347 """Checks that the bss matches the forced bssid, ssid and band.""" 00348 if self.scan_only: 00349 return False 00350 if not check_band(bss.frequency, self.forced_band): 00351 return False 00352 if self.forced_bssid and self.forced_bssid != bss.bssid: 00353 return False 00354 if self.forced_ssid and self.forced_ssid != bss.ssid: 00355 return False 00356 return True 00357 00358 def check_iface_matches_forcing(self, iface): 00359 if self.forced_iface and self.forced_iface != iface.iface: 00360 return False 00361 return True 00362 00363 def _new_scan_data(self): 00364 print "_new_scan_data" 00365 #print "\033[2J" 00366 #print "\033[0;0H" 00367 now = time.time() 00368 if now < self.initial_inhibit_end: 00369 print "inhibited" 00370 return 00371 for iface in self.interfaces: 00372 if not self.check_iface_matches_forcing(iface): 00373 continue 00374 00375 cur_assoc = iface.radio_sm.associated.get() 00376 #print "OK to try reassociating?", iface.iface, iface.radio_sm.scanning_enabled.get(), cur_assoc 00377 if cur_assoc and iface == self.best_active: 00378 continue 00379 00380 if iface.radio_sm.scanning_enabled.get() and cur_assoc != radio.Associating: 00381 # Pick the best bss for this interface. 00382 candidate_bsses = filter(self.check_bss_matches_forcing, 00383 self.scan_manager.bss_list.bsses.itervalues()) 00384 #print "Candidate bsses:", [mac_addr.pretty(bss.bssid) for bss in candidate_bsses] 00385 if candidate_bsses: 00386 expiry_time = now - self.bss_expiry_time 00387 best_bss = max(candidate_bsses, key = lambda bss: self.desirability(bss, expiry_time, iface)) 00388 if iface not in best_bss.by_iface or best_bss.by_iface[iface].stamp.to_sec() < expiry_time: 00389 print "Best bss is expired.", mac_addr.pretty(best_bss.bssid) 00390 best_bss = None 00391 else: 00392 print "No candidate bsses." 00393 best_bss = None 00394 if best_bss is None: 00395 print "No candidate bsses or expired." 00396 #print bool(candidate_bsses), [candidate_bsses] 00397 #print self.scan_manager.bss_list.bsses.values() 00398 continue 00399 00400 best_desirability = self.desirability(best_bss, expiry_time, iface) 00401 print "Best bss:", mac_addr.pretty(best_bss.bssid), best_desirability 00402 00403 if cur_assoc: 00404 # Are we already associated to the best AP? 00405 if make_id(cur_assoc) == best_bss.id: 00406 print "Already associated to best bss." 00407 continue 00408 00409 # Compute desirability for current association. 00410 cur_id = make_id(cur_assoc) 00411 if cur_id in self.scan_manager.bss_list.bsses: 00412 cur_bss = self.scan_manager.bss_list.bsses[make_id(cur_assoc)] 00413 cur_desirability = self.desirability(cur_bss, expiry_time, iface) 00414 else: 00415 cur_desirability = -1e1000 00416 00417 # Is the best ap better enough than the current best? 00418 if cur_desirability + self.reassociate_hysteresis > best_desirability: 00419 print "Best bss not over hysteresis threshold: %s %f > %s %f"%(mac_addr.pretty(cur_assoc.bssid), cur_desirability, mac_addr.pretty(best_bss.bssid), self.desirability(best_bss)) 00420 continue 00421 00422 # Let's associate 00423 print >> radio_manager_decisions, "Associating to %s (%f) on %s"%(mac_addr.pretty(best_bss.bssid), best_desirability, iface.iface), 00424 if cur_assoc: 00425 print >> radio_manager_decisions, "from %s (%f)"%(mac_addr.pretty(cur_assoc.bssid), cur_desirability) 00426 else: 00427 print >> radio_manager_decisions, "from unassociated" 00428 iface.radio_sm.associate_request.trigger(best_bss.id) 00429 self.iface_associations[iface] = best_bss.id 00430 00431 def _dhcp_fail(self, iface): 00432 print >> radio_manager_decisions, "DHCP failed, taking down", iface.iface 00433 iface.interface_upper.restart() 00434 00435 def _ping_fail(): 00436 pass 00437 00438 def update(self): 00439 """Called in the main update cycle after all the scores have been 00440 computed. Decides which interfaces should be activated.""" 00441 00442 def iface_score(iface): 00443 """Used to decide what to activate and disactivate.""" 00444 return iface.prescore 00445 00446 now = time.time() 00447 00448 active = set() 00449 verified = set() 00450 for iface in self.interfaces: 00451 iface.active = iface.radio_sm.is_active.get() 00452 if iface.active: 00453 active.add(iface) 00454 if iface.ping_monitor.is_verified.get(): 00455 verified.add(iface) 00456 inactive_verified = verified - active 00457 00458 # Only keep one active interface. 00459 if active: 00460 self.best_active = max(active, key = iface_score) 00461 else: 00462 self.best_active = None 00463 if len(active) > 1: 00464 for iface in active: 00465 if iface != self.best_active: 00466 iface.radio_sm.activate_request.set(False) 00467 print >> radio_manager_decisions, "XXX Disactivating %s because %s is active and better."%(iface.iface, self.best_active.iface) 00468 00469 # Activate a verified interface if it is better than the current 00470 # active interface. 00471 if inactive_verified: 00472 #print >> radio_manager_decisions, "Active interface selection." 00473 #for iface in verified: 00474 # print >> radio_manager_decisions, iface.iface, iface_score(iface), iface in active 00475 best_inactive_verified = max(inactive_verified, key = iface_score) 00476 if not self.best_active or iface_score(best_inactive_verified) > iface_score(self.best_active) + self.activate_hysteresis: 00477 if not self.best_active: 00478 print >> radio_manager_decisions, "XXX Activating %s because no current best active."%best_inactive_verified.iface 00479 else: 00480 print >> radio_manager_decisions, "XXX Activating %s because it is better than %s."%(best_inactive_verified.iface, self.best_active.iface) 00481 best_inactive_verified.radio_sm.activate_request.set(True) 00482 00483 # Keep a closer watch on the most relevant frequencies. 00484 #print self.scan_manager.bss_list.bsses 00485 #print [candidate_bsses] 00486 candidate_bsses = filter(self.check_bss_matches_forcing, 00487 self.scan_manager.bss_list.bsses.itervalues()) 00488 expiry_time = now - self.hot_bss_expiry_time 00489 candidate_bsses.sort(key = lambda bss: self.desirability(bss, expiry_time), reverse = True) 00490 #print [candidate_bsses] 00491 periods = dict((f, self.scan_manager.frequencies.scan_period_cold) 00492 for f in self.scan_manager.frequencies.frequencies) 00493 hot_frequencies = 0 00494 print >> scan_periods_log, "\033[2J\033[0;0H" 00495 print >> scan_periods_log, "Candidate bsses:" 00496 for bss in candidate_bsses: 00497 print >> scan_periods_log, bss.ssid, mac_addr.pretty(bss.bssid), bss.frequency, self.desirability(bss, expiry_time), now - bss.last_seen() 00498 if hot_frequencies < self.max_hot_frequencies and periods[bss.frequency] != self.scan_period_hot: 00499 hot_frequencies += 1 00500 p = self.scan_period_hot 00501 elif bss.last_seen(iface) > now - self.warm_bss_expiry_time: 00502 p = self.scan_period_warm 00503 periods[bss.frequency] = min(periods[bss.frequency], p) 00504 print >> scan_periods_log, "Frequencies" 00505 #for f in self.scan_manager.frequencies.frequencies: 00506 freqs = [ f for f in self.scan_manager.frequencies.frequencies if check_band(f, self.forced_band) ] 00507 freqs.sort() 00508 for f in freqs: 00509 print >> scan_periods_log, f, periods[f], self.scan_manager.frequencies.frequencies[f].next_scan_time - now 00510 self.scan_manager.frequencies.set_freq_period(f, periods[f]) 00511 00512 def desirability(self, target_bss, expiry_time = 0, iface = None): 00513 #print "desirability", mac_addr.pretty(target_bss.bssid), 00514 desirabilities = [bss.level for bss_iface, bss in target_bss.by_iface.iteritems() if bss.stamp.to_sec() > expiry_time and (iface is None or bss_iface == iface)] 00515 00516 if desirabilities: 00517 # If we are calculating desirability for a particular interface, 00518 # penalize if another interface is already associating/associated 00519 # to the bss. 00520 penalty = 0 00521 if iface: 00522 target_id = make_id(target_bss) 00523 for i, id in self.iface_associations.iteritems(): 00524 if i != iface and id == target_id: 00525 penalty = self.same_bss_penalty 00526 00527 #print max(desirabilities) 00528 return max(desirabilities) - penalty 00529 else: 00530 #print -1e1000 00531 return -1e1000 00532