February 2016 - tor-commits - lists.torproject.org

[stem/master] Skip udp addresses with a blank destination
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit f31cdcb4e9177fc123f6accd8d932657f57e1545 Author: Damian Johnson <atagar(a)torproject.org> Date: Sat Jan 30 15:21:25 2016 -0800 Skip udp addresses with a blank destination We can filter tcp connections by if the connection is established, but for udp we need to pick something else. Omitting addresses with a blank destination... * 127.0.0.1:53 => 0.0.0.0:0 (udp) * 0.0.0.0:45768 => 0.0.0.0:0 (udp) * 0.0.0.0:5353 => 0.0.0.0:0 (udp) * :::5353 => :::0 (udp) * :::36611 => :::0 (udp) --- stem/util/proc.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/stem/util/proc.py b/stem/util/proc.py index 40f9ba8..a0ceb8b 100644 --- a/stem/util/proc.py +++ b/stem/util/proc.py @@ -381,6 +381,8 @@ def connections(pid = None, user = None): continue elif protocol == 'tcp' and status != b'01': continue # skip tcp connections that aren't yet established + elif protocol == 'udp' and (f_addr == '00000000:0000' or f_addr == '00000000000000000000000000000000:0000'): + continue # skip udp connections with a blank destination local_ip, local_port = _decode_proc_address_encoding(l_addr, is_ipv6) foreign_ip, foreign_port = _decode_proc_address_encoding(f_addr, is_ipv6)

1 0

[stem/master] Expand caching of GETINFO results
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 68b912436444ba93e2b4c7db2644555fb3ddfe48 Author: Damian Johnson <atagar(a)torproject.org> Date: Sat Jan 30 18:40:15 2016 -0800 Expand caching of GETINFO results Caching several GETINFO queries that can only be changed with a SETCONF. These are queries nyx cares about, but we can expand the list as others crop up. --- stem/control.py | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/stem/control.py b/stem/control.py index 96597e8..8c30b28 100644 --- a/stem/control.py +++ b/stem/control.py @@ -347,6 +347,15 @@ CACHEABLE_GETINFO_PARAMS = ( 'events/names', 'features/names', 'process/descriptor-limit', + 'status/version/current', +) + +CACHEABLE_GETINFO_PARAMS_UNTIL_SETCONF = ( + 'accounting/enabled', + 'net/listeners/control', + 'net/listeners/dir', + 'net/listeners/or', + 'net/listeners/socks', ) # GETCONF parameters we shouldn't cache. This includes hidden service @@ -1120,7 +1129,7 @@ class Controller(BaseController): for key, value in response.entries.items(): key = key.lower() # make case insensitive - if key in CACHEABLE_GETINFO_PARAMS: + if key in CACHEABLE_GETINFO_PARAMS or key in CACHEABLE_GETINFO_PARAMS_UNTIL_SETCONF: to_cache[key] = value elif key.startswith('ip-to-country/'): # both cache-able and means that we should reset the geoip failure count @@ -2331,6 +2340,10 @@ class Controller(BaseController): if param == 'exitpolicy': self._set_cache({'exitpolicy': None}) + # reset any getinfo parameters that can be changed by a SETCONF + + self._set_cache(dict([(k.lower(), None) for k in CACHEABLE_GETINFO_PARAMS_UNTIL_SETCONF]), 'getinfo') + self._set_cache(to_cache, 'getconf') self._set_cache({'get_custom_options': None}) else:

1 0

[stem/master] Cache get_hidden_service_conf() responses
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 8e2ca2b42ccf4ac3e9db805926e7d259b6eaf9a5 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 12:06:09 2016 -0800 Cache get_hidden_service_conf() responses Nyx calls this quite a bit which is fine, but it bypasses our GETCONF cache. Adding a cache for this similar to our exit policy cache. Even after just a few seconds this caused thousands of calls so pretty important to nyx... % grep 'GETCONF HiddenServiceOptions (runtime' /tmp/dump | wc -l 6943 --- stem/control.py | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/stem/control.py b/stem/control.py index 8c30b28..cecc48b 100644 --- a/stem/control.py +++ b/stem/control.py @@ -2339,6 +2339,8 @@ class Controller(BaseController): if param == 'exitpolicy': self._set_cache({'exitpolicy': None}) + elif 'hidden' in param: + self._set_cache({'hidden_service_conf': None}) # reset any getinfo parameters that can be changed by a SETCONF @@ -2395,6 +2397,12 @@ class Controller(BaseController): provided a default response """ + service_dir_map = self._get_cache('hidden_service_conf') + + if service_dir_map is not None: + log.trace('GETCONF HiddenServiceOptions (cache fetch)') + return service_dir_map + start_time = time.time() try: @@ -2444,6 +2452,7 @@ class Controller(BaseController): else: service_dir_map[directory][k] = v + self._set_cache({'hidden_service_conf': service_dir_map}) return service_dir_map def set_hidden_service_conf(self, conf):

1 0

[stem/master] Don't log debug messages for multi-line config options
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 1b4f9dba0716982c7f942f66d28e8d6d622ccce1 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 12:22:00 2016 -0800 Don't log debug messages for multi-line config options Our config module supports multi-line strings but these cause us to log debug messages like the following... 01/31/2016 12:15:22 [DEBUG] Config entry 'config_options.Bridge.description' is expected to be of the format 'Key Value', defaulting to 'config_options.Bridge.description' -> '' Just a bug where we logged this warning before we had the handling for them. On reflection though this message doesn't have any value so simply dropping it. --- stem/util/conf.py | 17 ++++++----------- 1 file changed, 6 insertions(+), 11 deletions(-) diff --git a/stem/util/conf.py b/stem/util/conf.py index 134766c..a2763eb 100644 --- a/stem/util/conf.py +++ b/stem/util/conf.py @@ -512,14 +512,10 @@ class Config(object): # parse the key/value pair if line: - try: + if ' ' in line: key, value = line.split(' ', 1) - value = value.strip() - except ValueError: - log.debug("Config entry '%s' is expected to be of the format 'Key Value', defaulting to '%s' -> ''" % (line, line)) - key, value = line, '' - - if not value: + self.set(key, value.strip(), False) + else: # this might be a multi-line entry, try processing it as such multiline_buffer = [] @@ -529,10 +525,9 @@ class Config(object): multiline_buffer.append(content) if multiline_buffer: - self.set(key, '\n'.join(multiline_buffer), False) - continue - - self.set(key, value, False) + self.set(line, '\n'.join(multiline_buffer), False) + else: + self.set(line, '', False) # default to a key => '' mapping def save(self, path = None): """

1 0

[stem/master] Hook to disable trace logging for cache fetches
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit e378b22f7cd167cb66d9baf630858cec73f24b42 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 14:06:09 2016 -0800 Hook to disable trace logging for cache fetches Cache hits generally aren't very interesting and can generate a lot of noise. Providing an option so callers can disable them. --- stem/control.py | 13 ++++++++++--- 1 file changed, 10 insertions(+), 3 deletions(-) diff --git a/stem/control.py b/stem/control.py index cecc48b..8918426 100644 --- a/stem/control.py +++ b/stem/control.py @@ -323,6 +323,8 @@ Listener = stem.util.enum.UppercaseEnum( 'CONTROL', ) +LOG_CACHE_FETCHES = True # provide trace level logging for cache hits + # Configuration options that are fetched by a special key. The keys are # lowercase to make case insensitive lookups easier. @@ -1104,7 +1106,8 @@ class Controller(BaseController): # if everything was cached then short circuit making the query if not params: - log.trace('GETINFO %s (cache fetch)' % ' '.join(reply.keys())) + if LOG_CACHE_FETCHES: + log.trace('GETINFO %s (cache fetch)' % ' '.join(reply.keys())) if is_multiple: return reply @@ -2118,7 +2121,9 @@ class Controller(BaseController): # if everything was cached then short circuit making the query if not lookup_params: - log.trace('GETCONF %s (cache fetch)' % ' '.join(reply.keys())) + if LOG_CACHE_FETCHES: + log.trace('GETCONF %s (cache fetch)' % ' '.join(reply.keys())) + return self._get_conf_dict_to_response(reply, default, multiple) try: @@ -2400,7 +2405,9 @@ class Controller(BaseController): service_dir_map = self._get_cache('hidden_service_conf') if service_dir_map is not None: - log.trace('GETCONF HiddenServiceOptions (cache fetch)') + if LOG_CACHE_FETCHES: + log.trace('GETCONF HiddenServiceOptions (cache fetch)') + return service_dir_map start_time = time.time()

1 0

[stem/master] Truncate trace level logging
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 82a7ae8a2dd170bbf4ec3183ce170a107d73d116 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 13:57:16 2016 -0800 Truncate trace level logging At the trace level we have request/reply logging. Very useful, but some tor requests like 'GETINFO ns/all' are huge. Truncating responses to ten lines by default. This can be customized via a constant. This reduces the debug log when nyx is run for a few seconds from 1.6M to 80K, mostly because it no longer causes us to dump the full consensus into it. --- stem/socket.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/stem/socket.py b/stem/socket.py index 473debe..de57c7d 100644 --- a/stem/socket.py +++ b/stem/socket.py @@ -80,6 +80,10 @@ import stem.util.str_tools from stem.util import log +# lines to limit our trace logging to, you can disable this by setting it to None + +TRUNCATE_LOGS = 10 + class ControlSocket(object): """ @@ -589,6 +593,13 @@ def recv_message(control_file): raw_content_str = b''.join(raw_content) log_message = raw_content_str.replace(b'\r\n', b'\n').rstrip() + + if TRUNCATE_LOGS: + log_message_lines = log_message.split(b'\n') + + if len(log_message_lines) > TRUNCATE_LOGS: + log_message = b'\n'.join(log_message_lines[:TRUNCATE_LOGS] + [b'... %i more lines...' % (len(log_message_lines) - TRUNCATE_LOGS)]) + log.trace('Received from tor:\n' + stem.util.str_tools._to_unicode(log_message)) return stem.response.ControlMessage(parsed_content, raw_content_str)

1 0

[nyx/master] Cache 'GETINFO address' queries
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 48198becfdae7d6bc1d68862076a3c054246375e Author: Damian Johnson <atagar(a)torproject.org> Date: Sat Jan 30 18:45:29 2016 -0800 Cache 'GETINFO address' queries Very, very highly used GETINFO query. We can't legitimately make this cached in Stem since it can change but for Nyx it's a risk I'm willing to take. --- nyx/util/__init__.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/nyx/util/__init__.py b/nyx/util/__init__.py index 12b5ace..0f53ab6 100644 --- a/nyx/util/__init__.py +++ b/nyx/util/__init__.py @@ -7,6 +7,7 @@ import os import sys import stem.connection +import stem.control import stem.util.conf import stem.util.log @@ -26,6 +27,10 @@ BASE_DIR = os.path.sep.join(__file__.split(os.path.sep)[:-2]) DATA_DIR = os.path.expanduser('~/.nyx') TESTING = False +# technically can change but we use this query a *lot* so needs to be cached + +stem.control.CACHEABLE_GETINFO_PARAMS = list(stem.control.CACHEABLE_GETINFO_PARAMS) + ['address'] + try: uses_settings = stem.util.conf.uses_settings('nyx', os.path.join(BASE_DIR, 'config'), lazy_load = False) except IOError as exc:

1 0

[nyx/master] Don't individually query relays with get_relay_nickname()
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit ff84e0dab6177e61c3dc8dc924db68fdc9379e13 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 14:25:38 2016 -0800 Don't individually query relays with get_relay_nickname() The whole point of the consensus tracker is that it processes the whole consensus once to get what we need. Not sure why we made GETINFO queries for every call to get_relay_nickname() but changing it to match the other caches. --- nyx/util/tracker.py | 20 +++++++++----------- 1 file changed, 9 insertions(+), 11 deletions(-) diff --git a/nyx/util/tracker.py b/nyx/util/tracker.py index 237a01c..ffd24c9 100644 --- a/nyx/util/tracker.py +++ b/nyx/util/tracker.py @@ -777,7 +777,6 @@ class ConsensusTracker(object): tor_controller().add_event_listener(self._new_consensus_event, stem.control.EventType.NEWCONSENSUS) def _new_consensus_event(self, event): - self._nickname_cache = {} self.update(event.desc) def update(self, router_status_entries): @@ -789,13 +788,16 @@ class ConsensusTracker(object): new_fingerprint_cache = {} new_address_cache = {} + new_nickname_cache = {} for desc in router_status_entries: new_fingerprint_cache.setdefault(desc.address, []).append((desc.or_port, desc.fingerprint)) new_address_cache[desc.fingerprint] = (desc.address, desc.or_port) + new_nickname_cache[desc.fingerprint] = desc.nickname if desc.nickname else 'Unnamed' self._fingerprint_cache = new_fingerprint_cache self._address_cache = new_address_cache + self._nickname_cache = new_nickname_cache def get_relay_nickname(self, fingerprint): """ @@ -809,16 +811,12 @@ class ConsensusTracker(object): controller = tor_controller() - if fingerprint and fingerprint not in self._nickname_cache: - if fingerprint == controller.get_info('fingerprint', None): - self._nickname_cache[fingerprint] = controller.get_conf('Nickname', 'Unnamed') - else: - ns_entry = controller.get_network_status(fingerprint, None) - - if ns_entry: - self._nickname_cache[fingerprint] = ns_entry.nickname if ns_entry.nickname else 'Unnamed' - - return self._nickname_cache.get(fingerprint) + if not fingerprint: + return None + elif fingerprint == controller.get_info('fingerprint', None): + return controller.get_conf('Nickname', 'Unnamed') + else: + return self._nickname_cache.get(fingerprint) def get_relay_fingerprints(self, address): """

1 0

[nyx/master] Limit get_hidden_service_conf() queries
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit abeb4914fa60fed21c90de11eb63156a78a684cc Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 12:15:46 2016 -0800 Limit get_hidden_service_conf() queries We added caching to Stem so these aren't a big whoop but when we do debug logging it still means thousands of 'cached fetch' entries. Lets rate limit these queries. --- nyx/connection_panel.py | 22 +++++++++++++++------- 1 file changed, 15 insertions(+), 7 deletions(-) diff --git a/nyx/connection_panel.py b/nyx/connection_panel.py index 0024848..e28f531 100644 --- a/nyx/connection_panel.py +++ b/nyx/connection_panel.py @@ -30,7 +30,11 @@ DETAILS_HEIGHT = 7 EXIT_USAGE_WIDTH = 15 UPDATE_RATE = 5 # rate in seconds at which we refresh -LAST_RETRIEVED_CIRCUITS = None # cached circuit information from the last _update() call + +# cached information from our last _update() call + +LAST_RETRIEVED_HS_CONF = None +LAST_RETRIEVED_CIRCUITS = None # Connection Categories: # Inbound Relay connection, coming to us. @@ -179,9 +183,10 @@ class ConnectionEntry(Entry): elif self._connection.local_port in controller.get_ports(Listener.CONTROL, []): return Category.CONTROL - for hs_config in controller.get_hidden_service_conf({}).values(): - if self._connection.remote_port == hs_config['HiddenServicePort']: - return Category.HIDDEN + if LAST_RETRIEVED_HS_CONF: + for hs_config in LAST_RETRIEVED_HS_CONF.values(): + if self._connection.remote_port == hs_config['HiddenServicePort']: + return Category.HIDDEN fingerprint = nyx.util.tracker.get_consensus_tracker().get_relay_fingerprints(self._connection.remote_address).get(self._connection.remote_port) @@ -328,7 +333,7 @@ class ConnectionPanel(panel.Panel, threading.Thread): self.show_sort_dialog() elif key.match('r'): connection_tracker = nyx.util.tracker.get_connection_tracker() - options = ['auto'] + list(connection.Resolver) + options = ['auto'] + list(connection.Resolver) + list(nyx.util.tracker.CustomResolver) resolver = connection_tracker.get_custom_resolver() selected_index = 0 if resolver is None else options.index(resolver) @@ -648,7 +653,11 @@ class ConnectionPanel(panel.Panel, threading.Thread): Fetches the newest resolved connections. """ - global LAST_RETRIEVED_CIRCUITS + global LAST_RETRIEVED_CIRCUITS, LAST_RETRIEVED_HS_CONF + + controller = tor_controller() + LAST_RETRIEVED_CIRCUITS = controller.get_circuits([]) + LAST_RETRIEVED_HS_CONF = controller.get_hidden_service_conf({}) conn_resolver = nyx.util.tracker.get_connection_tracker() current_resolution_count = conn_resolver.run_counter() @@ -659,7 +668,6 @@ class ConnectionPanel(panel.Panel, threading.Thread): return # no new connections to process new_entries = [Entry.from_connection(conn) for conn in conn_resolver.get_value()] - LAST_RETRIEVED_CIRCUITS = tor_controller().get_circuits([]) for circ in LAST_RETRIEVED_CIRCUITS: # Skips established single-hop circuits (these are for directory

1 0

[nyx/master] Limit 'GETINFO circuit-status' requests
by atagar＠torproject.org 01 Feb '16

01 Feb '16

commit 837b6e6be80162daf3664e8926689e65e638d126 Author: Damian Johnson <atagar(a)torproject.org> Date: Sun Jan 31 11:52:25 2016 -0800 Limit 'GETINFO circuit-status' requests This getinfo query carries some heft and we triggered one for every connection. After even only a few seconds this is rediculously heavy... % grep 'GETINFO circuit-status' /tmp/debug_log | wc -l 2253 --- nyx/connection_panel.py | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/nyx/connection_panel.py b/nyx/connection_panel.py index cf4286c..0024848 100644 --- a/nyx/connection_panel.py +++ b/nyx/connection_panel.py @@ -30,6 +30,7 @@ DETAILS_HEIGHT = 7 EXIT_USAGE_WIDTH = 15 UPDATE_RATE = 5 # rate in seconds at which we refresh +LAST_RETRIEVED_CIRCUITS = None # cached circuit information from the last _update() call # Connection Categories: # Inbound Relay connection, coming to us. @@ -184,13 +185,10 @@ class ConnectionEntry(Entry): fingerprint = nyx.util.tracker.get_consensus_tracker().get_relay_fingerprints(self._connection.remote_address).get(self._connection.remote_port) - if fingerprint: - for circ in controller.get_circuits([]): - if circ.path and circ.path[0][0] == fingerprint and circ.status == 'BUILT': - # Tor builds one-hop circuits to retrieve directory information. - # If longer this is likely a connection to a guard. - - return Category.DIRECTORY if len(circ.path) == 1 else Category.CIRCUIT + if fingerprint and LAST_RETRIEVED_CIRCUITS: + for circ in LAST_RETRIEVED_CIRCUITS: + if circ.path and len(circ.path) == 1 and circ.path[0][0] == fingerprint and circ.status == 'BUILT': + return Category.DIRECTORY # one-hop circuit to retrieve directory information else: # not a known relay, might be an exit connection @@ -235,7 +233,7 @@ class CircuitEntry(Entry): nickname = consensus_tracker.get_relay_nickname(fingerprint) locale = tor_controller().get_info('ip-to-country/%s' % address, None) - connection = nyx.util.tracker.Connection(datetime_to_unix(self._circuit.created), False, '127.0.0.1', 0, address, port, 'tcp') + connection = nyx.util.tracker.Connection(datetime_to_unix(self._circuit.created), False, '127.0.0.1', 0, address, port, 'tcp', False) return Line(self, line_type, connection, self._circuit, fingerprint, nickname, locale) header_line = line(self._circuit.path[-1][0] if self._circuit.status == 'BUILT' else None, LineType.CIRCUIT_HEADER) @@ -650,6 +648,8 @@ class ConnectionPanel(panel.Panel, threading.Thread): Fetches the newest resolved connections. """ + global LAST_RETRIEVED_CIRCUITS + conn_resolver = nyx.util.tracker.get_connection_tracker() current_resolution_count = conn_resolver.run_counter() @@ -659,8 +659,9 @@ class ConnectionPanel(panel.Panel, threading.Thread): return # no new connections to process new_entries = [Entry.from_connection(conn) for conn in conn_resolver.get_value()] + LAST_RETRIEVED_CIRCUITS = tor_controller().get_circuits([]) - for circ in tor_controller().get_circuits([]): + for circ in LAST_RETRIEVED_CIRCUITS: # Skips established single-hop circuits (these are for directory # fetches, not client circuits)

1 0