def __start_tor(self, name, control_port, socks_port, hs_port_mapping=None):
logging.info("Starting Tor {0} process with ControlPort={1}, SocksPort={2}...".format(name, control_port, socks_port))
tor_datadir = "{0}/tor-{1}".format(self.datadir_path, name)
if not os.path.exists(tor_datadir): os.makedirs(tor_datadir)
tor_config_template = "ORPort 0\nDirPort 0\nControlPort {0}\nSocksPort {1}\nSocksListenAddress 127.0.0.1\nClientOnly 1\n\
WarnUnsafeSocks 0\nSafeLogging 0\nMaxCircuitDirtiness 60 seconds\nUseEntryGuards 0\nDataDirectory {2}\nLog INFO stdout\n"
tor_config = tor_config_template.format(control_port, socks_port, tor_datadir)
tor_logpath = "{0}/onionperf.tor.log".format(tor_datadir)
tor_writable = util.FileWritable(tor_logpath)
logging.info("Logging Tor {0} process output to {1}".format(name, tor_logpath))
# from stem.process import launch_tor_with_config
# tor_subp = launch_tor_with_config(tor_config, tor_cmd=self.tor_bin_path, completion_percent=100, init_msg_handler=None, timeout=None, take_ownership=False)
tor_cmd = "{0} -f -".format(self.tor_bin_path)
tor_stdin_bytes = str_tools._to_bytes(tor_config)
tor_ready_str = "Bootstrapped 100"
tor_ready_ev = threading.Event()
tor_args = (tor_cmd, tor_datadir, tor_writable, self.done_event, tor_stdin_bytes, tor_ready_str, tor_ready_ev)
tor_watchdog = threading.Thread(target=watchdog_thread_task, name="tor_{0}_watchdog".format(name), args=tor_args)
tor_watchdog.start()
self.threads.append(tor_watchdog)
# wait until Tor finishes bootstrapping
tor_ready_ev.wait()
torctl_logpath = "{0}/onionperf.torctl.log".format(tor_datadir)
torctl_writable = util.FileWritable(torctl_logpath)
logging.info("Logging Tor {0} control port monitor output to {1}".format(name, torctl_logpath))
# give a few seconds to make sure Tor had time to start listening on the control port
time.sleep(3)
torctl_events = [e for e in monitor.get_supported_torctl_events() if e not in ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR']]
newnym_interval_seconds = 300
torctl_args = (control_port, torctl_writable, torctl_events, newnym_interval_seconds, self.done_event)
torctl_helper = threading.Thread(target=monitor.tor_monitor_run, name="torctl_{0}_helper".format(name), args=torctl_args)
torctl_helper.start()
self.threads.append(torctl_helper)
if hs_port_mapping is not None:
logging.info("Creating ephemeral hidden service with v2 onions...")
with Controller.from_port(port=control_port) as torctl:
torctl.authenticate()
response = torctl.create_ephemeral_hidden_service(hs_port_mapping, detached=True, await_publication=True)
self.hs_service_id = response.service_id
self.hs_control_port = control_port
logging.info("Ephemeral hidden service is available at {0}.onion".format(response.service_id))
logging.info("Creating ephemeral hidden service with v3 onions...")
with Controller.from_port(port=control_port) as torctl:
torctl.authenticate()
response = torctl.create_ephemeral_hidden_service(hs_port_mapping, detached=True, await_publication=True, key_content='ED25519-V3')
self.hs_v3_service_id = response.service_id
self.hs_v3_control_port = control_port
logging.info("Ephemeral hidden service is available at {0}.onion".format(response.service_id))
return tor_writable, torctl_writable
def __start_tgen(self, name, tgen_port, socks_port=None, server_urls=None):
logging.info("Starting TGen {0} process on port {1}...".format(
name, tgen_port))
tgen_datadir = "{0}/tgen-{1}".format(self.datadir_path, name)
if not os.path.exists(tgen_datadir): os.makedirs(tgen_datadir)
tgen_confpath = "{0}/tgen.graphml.xml".format(tgen_datadir)
if os.path.exists(tgen_confpath): os.remove(tgen_confpath)
if socks_port is None:
model.ListenModel(
tgen_port="{0}".format(tgen_port)).dump_to_file(tgen_confpath)
logging.info(
"TGen server running at 0.0.0.0:{0}".format(tgen_port))
else:
model.TorperfModel(tgen_port="{0}".format(tgen_port),
tgen_servers=server_urls,
socksproxy="127.0.0.1:{0}".format(
socks_port)).dump_to_file(tgen_confpath)
tgen_logpath = "{0}/onionperf.tgen.log".format(tgen_datadir)
tgen_writable = util.FileWritable(tgen_logpath)
logging.info("Logging TGen {1} process output to {0}".format(
tgen_logpath, name))
tgen_cmd = "{0} {1}".format(self.tgen_bin_path, tgen_confpath)
tgen_args = (tgen_cmd, tgen_datadir, tgen_writable, self.done_event,
None, None, None)
tgen_watchdog = threading.Thread(target=watchdog_thread_task,
name="tgen_{0}_watchdog".format(name),
args=tgen_args)
tgen_watchdog.start()
self.threads.append(tgen_watchdog)
return tgen_writable
def __start_twistd(self, twistd_port):
logging.info("Starting Twistd server process on port {0}...".format(
twistd_port))
twisted_datadir = "{0}/twistd".format(self.datadir_path)
if not os.path.exists(twisted_datadir): os.makedirs(twisted_datadir)
twisted_logpath = "{0}/onionperf.twisted.log".format(twisted_datadir)
twisted_writable = util.FileWritable(twisted_logpath)
logging.info(
"Logging Twisted process output to {0}".format(twisted_logpath))
twisted_docroot = "{0}/docroot".format(twisted_datadir)
if not os.path.exists(twisted_docroot): os.makedirs(twisted_docroot)
generate_docroot_index(twisted_docroot)
self.twisted_docroot = twisted_docroot
twisted_cmd = "{0} -n -l - web --port {1} --path {2} --mime-type=None".format(
self.twistd_bin_path, twistd_port, twisted_docroot)
twisted_args = (twisted_cmd, twisted_datadir, twisted_writable,
self.done_event, None, None, None)
twisted_watchdog = threading.Thread(target=watchdog_thread_task,
name="twistd_watchdog",
args=twisted_args)
twisted_watchdog.start()
self.threads.append(twisted_watchdog)
logging.info(
"Twistd web server running at 0.0.0.0:{0}".format(twistd_port))
return twisted_writable
def save(self,
filename=None,
output_prefix=os.getcwd(),
do_compress=True,
version=1.0):
if filename is None:
if self.date_filter is None:
filename = "onionperf.analysis.json.xz"
else:
filename = "{}.onionperf.analysis.json.xz".format(
util.date_to_string(self.date_filter))
filepath = os.path.abspath(
os.path.expanduser("{0}/{1}".format(output_prefix, filename)))
if not os.path.exists(output_prefix):
os.makedirs(output_prefix)
logging.info("saving analysis results to {0}".format(filepath))
outf = util.FileWritable(filepath, do_compress=do_compress)
json.dump(self.json_db,
outf,
sort_keys=True,
separators=(',', ': '),
indent=2)
outf.close()
logging.info("done!")
def __start_tor(self, name, control_port, socks_port, hs_port_mapping=None):
logging.info("Starting Tor {0} process with ControlPort={1}, SocksPort={2}...".format(name, control_port, socks_port))
tor_datadir = "{0}/tor-{1}".format(self.datadir_path, name)
key_path_v2 = "{0}/os_key_v2".format(self.privatedir_path)
key_path_v3 = "{0}/os_key_v3".format(self.privatedir_path)
if not os.path.exists(tor_datadir): os.makedirs(tor_datadir)
tor_config = self.create_tor_config(control_port,socks_port,tor_datadir,name)
tor_logpath = "{0}/onionperf.tor.log".format(tor_datadir)
tor_writable = util.FileWritable(tor_logpath)
logging.info("Logging Tor {0} process output to {1}".format(name, tor_logpath))
# from stem.process import launch_tor_with_config
# tor_subp = launch_tor_with_config(tor_config, tor_cmd=self.tor_bin_path, completion_percent=100, init_msg_handler=None, timeout=None, take_ownership=False)
tor_cmd = "{0} -f -".format(self.tor_bin_path)
tor_stdin_bytes = str_tools._to_bytes(tor_config)
tor_ready_str = "Bootstrapped 100"
tor_ready_ev = threading.Event()
tor_args = (tor_cmd, tor_datadir, tor_writable, self.done_event, tor_stdin_bytes, tor_ready_str, tor_ready_ev)
tor_watchdog = threading.Thread(target=watchdog_thread_task, name="tor_{0}_watchdog".format(name), args=tor_args)
tor_watchdog.start()
self.threads.append(tor_watchdog)
# wait until Tor finishes bootstrapping
tor_ready_ev.wait()
torctl_logpath = "{0}/onionperf.torctl.log".format(tor_datadir)
torctl_writable = util.FileWritable(torctl_logpath)
logging.info("Logging Tor {0} control port monitor output to {1}".format(name, torctl_logpath))
# give a few seconds to make sure Tor had time to start listening on the control port
time.sleep(3)
torctl_events = [e for e in monitor.get_supported_torctl_events() if e not in ['DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERR']]
newnym_interval_seconds = 300
torctl_args = (control_port, torctl_writable, torctl_events, newnym_interval_seconds, self.done_event)
torctl_helper = threading.Thread(target=monitor.tor_monitor_run, name="torctl_{0}_helper".format(name), args=torctl_args)
torctl_helper.start()
self.threads.append(torctl_helper)
if hs_port_mapping is not None:
self.start_onion_service(control_port, hs_port_mapping, key_path_v2)
self.start_onion_service(control_port, hs_port_mapping, key_path_v3, v3=True)
return tor_writable, torctl_writable
def export_torperf_version_1_0(self, output_prefix=os.getcwd(), datetimestamp=None, do_compress=False):
# export file in `@type torperf 1.0` format: https://collector.torproject.org/#type-torperf
if not os.path.exists(output_prefix):
os.makedirs(output_prefix)
if datetimestamp is None:
datetimestamp = datetime.datetime.utcnow()
datestr = "{0:04d}-{1:02d}-{2:02d}".format(datetimestamp.year, datetimestamp.month, datetimestamp.day)
for nickname in self.json_db['data']:
if 'tgen' not in self.json_db['data'][nickname] or 'transfers' not in self.json_db['data'][nickname]['tgen']:
continue
xfers_by_filesize = {}
for xfer_db in self.json_db['data'][nickname]['tgen']['transfers'].values():
xfers_by_filesize.setdefault(xfer_db['filesize_bytes'], []).append(xfer_db)
streams_by_srcport = {}
for streams_db in self.json_db['data'][nickname]['tor']['streams'].values():
if 'source' in streams_db:
srcport = int(streams_db['source'].split(':')[1])
streams_by_srcport[srcport] = streams_db
circuits = self.json_db['data'][nickname]['tor']['circuits']
for filesize in xfers_by_filesize:
filepath = "{0}/{1}-{2}-{3}.tpf{4}".format(output_prefix, nickname, filesize, datestr, '.xz' if do_compress else '')
logging.info("saving analysis results to {0}".format(filepath))
# always append instead of truncating file
output = util.FileWritable(filepath, do_compress=do_compress, do_truncate=False)
output.open()
for xfer_db in xfers_by_filesize[filesize]:
# if any keys are missing, log a warning
try:
d = {}
d['SOURCE'] = nickname
d['ENDPOINTLOCAL'] = xfer_db['endpoint_local']
d['ENDPOINTPROXY'] = xfer_db['endpoint_proxy']
d['ENDPOINTREMOTE'] = xfer_db['endpoint_remote']
d['HOSTNAMELOCAL'] = xfer_db['hostname_local']
d['HOSTNAMEREMOTE'] = xfer_db['hostname_remote']
d['FILESIZE'] = xfer_db['filesize_bytes']
d['READBYTES'] = xfer_db['total_bytes_read']
d['WRITEBYTES'] = xfer_db['total_bytes_write']
def ts_to_str(ts): return"{0:.02f}".format(ts)
# initialize times to 0.0
time_keys = ['START', 'SOCKET', 'CONNECT', 'NEGOTIATE', 'REQUEST', 'RESPONSE', 'DATAREQUEST', 'DATARESPONSE', 'DATACOMPLETE', 'LAUNCH']
for i in range(1, 10):
time_keys.append('DATAPERC{}0'.format(i))
for key in time_keys:
d[key] = 0.0
# since these are initialized to 0, it's OK if we are missing some times, e.g. due to read error
if 'unix_ts_start' in xfer_db:
d['START'] = ts_to_str(xfer_db['unix_ts_start'])
if 'elapsed_seconds' in xfer_db:
if 'socket_create' in xfer_db['elapsed_seconds']:
d['SOCKET'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['socket_create'])
if 'socket_connect' in xfer_db['elapsed_seconds']:
d['CONNECT'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['socket_connect'])
if 'proxy_choice' in xfer_db['elapsed_seconds']:
d['NEGOTIATE'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['proxy_choice'])
if 'proxy_request' in xfer_db['elapsed_seconds']:
d['REQUEST'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['proxy_request'])
if 'proxy_response' in xfer_db['elapsed_seconds']:
d['RESPONSE'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['proxy_response'])
if 'command' in xfer_db['elapsed_seconds']:
d['DATAREQUEST'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['command'])
if 'response' in xfer_db['elapsed_seconds']:
d['DATARESPONSE'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['response'])
if 'payload_progress' in xfer_db['elapsed_seconds']:
# set DATAPERC[10,20,...,90]
for decile in sorted(xfer_db['elapsed_seconds']['payload_progress'].keys()):
if decile in xfer_db['elapsed_seconds']['payload_progress'] and xfer_db['elapsed_seconds']['payload_progress'][decile] is not None:
d['DATAPERC{0}'.format(int(decile * 100))] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['payload_progress'][decile])
if 'last_byte' in xfer_db['elapsed_seconds']:
d['DATACOMPLETE'] = ts_to_str(xfer_db['unix_ts_start'] + xfer_db['elapsed_seconds']['last_byte'])
# could be ioerror or timeout or etc, but i dont think torperf distinguishes these
d['DIDTIMEOUT'] = 1 if xfer_db['is_error'] is True else 0
# now get the tor parts
srcport = int(xfer_db['endpoint_local'].split(':')[2])
if srcport in streams_by_srcport:
stream_db = streams_by_srcport[srcport]
circid = int(stream_db['circuit_id'])
if circid in circuits:
circuit_db = circuits[circid]
d['LAUNCH'] = circuit_db['unix_ts_start']
d['PATH'] = ','.join([item[0].split('~')[0] for item in circuit_db['path']])
d['BUILDTIMES'] = ','.join([str(item[1]) for item in circuit_db['path']])
d['TIMEOUT'] = circuit_db['build_timeout'] if 'build_timeout' in circuit_db else None
d['QUANTILE'] = circuit_db['build_quantile'] if 'build_quantile' in circuit_db else None
d['CIRC_ID'] = circid
d['USED_AT'] = stream_db['unix_ts_end']
d['USED_BY'] = int(stream_db['stream_id'])
output.write("@type torperf 1.0\r\n")
output_str = ' '.join("{0}={1}".format(k, d[k]) for k in sorted(d.keys()) if d[k] is not None).strip()
output.write("{0}\r\n".format(output_str))
except KeyError, e:
logging.warning("KeyError while exporting torperf file, missing key '{0}', skipping transfer '{1}'".format(str(e), xfer_db['transfer_id']))
continue
output.close()
logging.info("done!")
def export_torperf_version_1_1(self,
output_prefix=os.getcwd(),
do_compress=False):
# export file in `@type torperf 1.0` format: https://collector.torproject.org/#type-torperf
if not os.path.exists(output_prefix):
os.makedirs(output_prefix)
for nickname in self.json_db['data']:
if 'tgen' not in self.json_db['data'][
nickname] or 'transfers' not in self.json_db['data'][
nickname]['tgen']:
continue
xfers_by_filesize = {}
for xfer_db in self.json_db['data'][nickname]['tgen'][
'transfers'].values():
xfers_by_filesize.setdefault(xfer_db['filesize_bytes'],
[]).append(xfer_db)
streams_by_srcport, circuits = {}, []
if 'tor' in self.json_db['data'][nickname]:
if 'streams' in self.json_db['data'][nickname]['tor']:
for streams_db in self.json_db['data'][nickname]['tor'][
'streams'].values():
if 'source' in streams_db:
srcport = int(streams_db['source'].split(':')[1])
streams_by_srcport[srcport] = streams_db
if 'circuits' in self.json_db['data'][nickname]['tor']:
circuits = self.json_db['data'][nickname]['tor'][
'circuits']
for filesize in xfers_by_filesize:
# build the filename
filename_prefix = "{}-{}".format(nickname, filesize)
filename_middle = "-{}".format(
util.date_to_string(self.date_filter)
) if self.date_filter is not None else ""
filename_suffix = ".tpf.xz" if do_compress else ".tpf"
filename = "{}{}{}".format(filename_prefix, filename_middle,
filename_suffix)
filepath = "{}/{}".format(output_prefix, filename)
logging.info("saving analysis results to {0}".format(filepath))
# always append instead of truncating file
output = util.FileWritable(filepath,
do_compress=do_compress,
do_truncate=False)
output.open()
for xfer_db in xfers_by_filesize[filesize]:
# if any keys are missing, log a warning
try:
d = {}
d['SOURCE'] = nickname
d['SOURCEADDRESS'] = self.json_db['data'][nickname][
'measurement_ip']
d['ENDPOINTLOCAL'] = xfer_db['endpoint_local']
d['ENDPOINTPROXY'] = xfer_db['endpoint_proxy']
d['ENDPOINTREMOTE'] = xfer_db['endpoint_remote']
d['HOSTNAMELOCAL'] = xfer_db['hostname_local']
d['HOSTNAMEREMOTE'] = xfer_db['hostname_remote']
d['FILESIZE'] = xfer_db['filesize_bytes']
d['READBYTES'] = xfer_db['total_bytes_read']
d['WRITEBYTES'] = xfer_db['total_bytes_write']
d['DIDTIMEOUT'] = 0
def ts_to_str(ts):
return "{0:.02f}".format(ts)
# initialize times to 0.0
time_keys = [
'START', 'SOCKET', 'CONNECT', 'NEGOTIATE',
'REQUEST', 'RESPONSE', 'DATAREQUEST',
'DATARESPONSE', 'DATACOMPLETE', 'LAUNCH'
]
for i in range(1, 10):
time_keys.append('DATAPERC{}0'.format(i))
for key in time_keys:
d[key] = 0.0
# since these are initialized to 0, it's OK if we are missing some times, e.g. due to read error
if 'unix_ts_start' in xfer_db:
# if we need to filter by date and the download did not start on that date, skip it
if self.date_filter is not None:
start_datetime = datetime.datetime.utcfromtimestamp(
xfer_db['unix_ts_start'])
if start_datetime is not None:
if not util.do_dates_match(
self.date_filter,
start_datetime.date()):
logging.info(
"skipping download because start date {} does not match filter date {}"
.format(
util.date_to_string(
start_datetime.date()),
util.date_to_string(
self.date_filter)))
continue
d['START'] = ts_to_str(xfer_db['unix_ts_start'])
if 'elapsed_seconds' in xfer_db:
if 'socket_create' in xfer_db[
'elapsed_seconds']:
d['SOCKET'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['socket_create'])
if 'socket_connect' in xfer_db[
'elapsed_seconds']:
d['CONNECT'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['socket_connect'])
if 'proxy_choice' in xfer_db[
'elapsed_seconds']:
d['NEGOTIATE'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['proxy_choice'])
if 'proxy_request' in xfer_db[
'elapsed_seconds']:
d['REQUEST'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['proxy_request'])
if 'proxy_response' in xfer_db[
'elapsed_seconds']:
d['RESPONSE'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['proxy_response'])
if 'command' in xfer_db['elapsed_seconds']:
d['DATAREQUEST'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']['command'])
if 'response' in xfer_db['elapsed_seconds']:
d['DATARESPONSE'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']['response'])
if 'payload_progress' in xfer_db[
'elapsed_seconds']:
# set DATAPERC[10,20,...,90]
for decile in sorted(
xfer_db['elapsed_seconds']
['payload_progress'].keys()):
if decile in xfer_db['elapsed_seconds'][
'payload_progress'] and xfer_db[
'elapsed_seconds'][
'payload_progress'][
decile] is not None:
decile_as_int = int(
float(decile) * 100)
d['DATAPERC{0}'.format(
decile_as_int
)] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']
['payload_progress'][decile])
else:
for i in range(1, 10):
d.pop('DATAPERC{}0'.format(i))
if 'last_byte' in xfer_db['elapsed_seconds']:
d['DATACOMPLETE'] = ts_to_str(
xfer_db['unix_ts_start'] +
xfer_db['elapsed_seconds']['last_byte']
)
if xfer_db['is_error']:
d['DIDTIMEOUT'] = 1 # could be ioerror or timeout or etc, torperf did not distinguish
d['ERRORCODE'] = xfer_db[
'error_code'] # this field is onionperf specific
# now get the tor parts
srcport = int(xfer_db['endpoint_local'].split(':')[2])
if srcport in streams_by_srcport:
stream_db = streams_by_srcport[srcport]
if 'failure_reason_local' in stream_db.keys():
d['ERRORCODE'] += '_' + stream_db[
'failure_reason_local']
if 'failure_reason_remote' in stream_db.keys():
d['ERRORCODE'] += '_' + stream_db[
'failure_reason_remote']
circid = int(stream_db['circuit_id'] or 0)
if circid in circuits:
circuit_db = circuits[circid]
d['LAUNCH'] = circuit_db['unix_ts_start']
d['PATH'] = ','.join([
item[0].split('~')[0]
for item in circuit_db['path']
])
d['BUILDTIMES'] = ','.join([
str(item[1]) for item in circuit_db['path']
])
d['TIMEOUT'] = circuit_db[
'build_timeout'] if 'build_timeout' in circuit_db else None
d['QUANTILE'] = circuit_db[
'build_quantile'] if 'build_quantile' in circuit_db else None
d['CIRC_ID'] = circid
d['USED_AT'] = stream_db['unix_ts_end']
d['USED_BY'] = int(stream_db['stream_id'])
if 'ERRORCODE' in d.keys():
d['ERRORCODE'] = ERRORS[d['ERRORCODE']]
output.write("@type torperf 1.1\r\n")
output_str = ' '.join("{0}={1}".format(k, d[k])
for k in sorted(d.keys())
if d[k] is not None).strip()
output.write("{0}\r\n".format(output_str))
except KeyError, e:
logging.warning(
"KeyError while exporting torperf file, missing key '{0}', skipping transfer '{1}'"
.format(str(e), xfer_db['transfer_id']))
continue
output.close()
logging.info("done!")