From 4840050e8612ccca8f7640938535cfa26d66d243 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Arturo=20Filast=C3=B2?= Date: Fri, 12 Aug 2022 13:44:46 +0200 Subject: [PATCH 1/5] Handle the new format of vanilla_tor experiment Fixes: https://github.com/ooni/backend/issues/608 --- af/fastpath/fastpath/core.py | 21 ++++++++++++++++----- 1 file changed, 16 insertions(+), 5 deletions(-) diff --git a/af/fastpath/fastpath/core.py b/af/fastpath/fastpath/core.py index 653447e0..ee2b9f90 100644 --- a/af/fastpath/fastpath/core.py +++ b/af/fastpath/fastpath/core.py @@ -902,17 +902,28 @@ def score_vanilla_tor(msm): if msm["software_name"] == "ooniprobe" and all_keys_none(tk, nks): if tk["tor_progress"] == 0: # client bug? + scores["accuracy"] = 0.0 scores["msg"] = "Client bug" return scores - tor_log = tk.get("tor_log") - if tor_log is None: + tor_logs = [] + # Handle incompatibility with legacy test: + # https://github.com/ooni/spec/blob/master/nettests/ts-016-vanilla-tor.md#incompatibility-with-ooniprobe-legacy + if "tor_logs" in tk and tk["tor_logs"]: + tor_logs = tk["tor_logs"] + elif "tor_log" in tk and tk["tor_log"]: + tor_logs = tk["tor_log"].split("\n") + + if len(tor_logs) == 0: # unknown bug + scores["accuracy"] = 0.0 return scores - if ( - "Bootstrapped 100%: Done" in tor_log - or "Bootstrapped 100% (done): Done" in tor_log + if any( + [ + "Bootstrapped 100%: Done" in tl or "Bootstrapped 100% (done): Done" in tl + for tl in tor_logs + ] ): # Success return scores From 579dc926d7d5bd5826bc498ccd5ccb077a5c5b6a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Arturo=20Filast=C3=B2?= Date: Fri, 12 Aug 2022 14:00:17 +0200 Subject: [PATCH 2/5] Add test cases for vanilla_tor test --- .../tests/data/vanilla_tor_bad_new.json | 1 + .../tests/data/vanilla_tor_bad_old.json | 1 + .../tests/data/vanilla_tor_good_new.json | 1 + .../tests/data/vanilla_tor_good_old.json | 1 + af/fastpath/fastpath/tests/test_unit.py | 18 ++++++++++++++++++ 5 files changed, 22 insertions(+) create mode 100644 af/fastpath/fastpath/tests/data/vanilla_tor_bad_new.json create mode 100644 af/fastpath/fastpath/tests/data/vanilla_tor_bad_old.json create mode 100644 af/fastpath/fastpath/tests/data/vanilla_tor_good_new.json create mode 100644 af/fastpath/fastpath/tests/data/vanilla_tor_good_old.json diff --git a/af/fastpath/fastpath/tests/data/vanilla_tor_bad_new.json b/af/fastpath/fastpath/tests/data/vanilla_tor_bad_new.json new file mode 100644 index 00000000..cedd6e0b --- /dev/null +++ b/af/fastpath/fastpath/tests/data/vanilla_tor_bad_new.json @@ -0,0 +1 @@ +{"annotations":{"architecture":"arm64","engine_name":"ooniprobe-engine","engine_version":"3.15.2","flavor":"stableFdroid","network_type":"wifi","origin":"autorun","platform":"android"},"data_format_version":"0.2.0","input":null,"measurement_start_time":"2022-08-02 21:55:29","probe_asn":"AS17623","probe_cc":"CN","probe_ip":"127.0.0.1","probe_network_name":"China Unicom Shenzen network","report_id":"20220802T215209Z_vanillator_CN_17623_n1_LXFdyo7ao2kE7sQj","resolver_asn":"AS17623","resolver_ip":"27.40.22.154","resolver_network_name":"China Unicom Shenzen network","software_name":"ooniprobe-android-unattended","software_version":"3.7.0","test_keys":{"bootstrap_time":0,"error":"timeout-reached","failure":"generic_timeout_error","success":false,"timeout":200,"tor_logs":["Aug 03 05:52:09.000 [notice] Bootstrapped 0% (starting): Starting","Aug 03 05:52:09.000 [notice] Bootstrapped 5% (conn): Connecting to a relay"],"tor_progress":5,"tor_progress_tag":"conn","tor_progress_summary":"Connecting to a relay","tor_version":"0.4.6.10-dev","transport_name":"vanilla"},"test_name":"vanilla_tor","test_runtime":200.02608409,"test_start_time":"2022-08-02 21:52:07","test_version":"0.2.0"} diff --git a/af/fastpath/fastpath/tests/data/vanilla_tor_bad_old.json b/af/fastpath/fastpath/tests/data/vanilla_tor_bad_old.json new file mode 100644 index 00000000..94443a12 --- /dev/null +++ b/af/fastpath/fastpath/tests/data/vanilla_tor_bad_old.json @@ -0,0 +1 @@ +{"test_keys": {"transport_name": "vanilla", "success": false, "tor_log": "Oct 07 07:33:17.000 [notice] Tor 0.2.9.10 (git-e28303bcf90b842d) opening new log file.\nOct 07 07:33:17.346 [notice] Tor 0.2.9.10 (git-e28303bcf90b842d) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.1t and Zlib 1.2.8.\nOct 07 07:33:17.346 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning\nOct 07 07:33:17.347 [notice] Configuration file \"/non-existant\" not present, using reasonable defaults.\nOct 07 07:33:17.378 [notice] Opening Socks listener on 127.0.0.1:27178\nOct 07 07:33:17.378 [notice] Opening Control listener on 127.0.0.1:58496\nOct 07 07:33:17.000 [notice] Parsing GEOIP IPv4 file /usr/share/tor/geoip.\nOct 07 07:33:19.000 [notice] Parsing GEOIP IPv6 file /usr/share/tor/geoip6.\nOct 07 07:33:20.000 [warn] You are running Tor as root. You don't need to, and you probably shouldn't.\nOct 07 07:33:23.000 [notice] Bootstrapped 0%: Starting\nOct 07 07:33:23.000 [notice] Bootstrapped 5%: Connecting to directory server\nOct 07 07:33:23.000 [notice] New control connection opened from 127.0.0.1.\nOct 07 07:33:23.000 [notice] Tor 0.2.9.10 (git-e28303bcf90b842d) opening log file.\nOct 07 07:38:15.000 [notice] Catching signal TERM, exiting cleanly.\n", "tor_progress_tag": "conn_dir", "tor_progress": 5, "timeout": 300, "error": "timeout-reached", "tor_version": "0.2.9.10", "tor_progress_summary": "Connecting to directory server"}, "software_version": "2.2.0", "test_runtime": 300.17800116539, "test_start_time": "2017-10-07 07:33:08", "input_hashes": [], "software_name": "ooniprobe", "options": [], "data_format_version": "0.2.0", "measurement_start_time": "2017-10-07 07:33:15", "test_version": "0.1.0", "probe_city": null, "test_name": "vanilla_tor", "id": "14632cd4-1469-4e36-98ed-b1da0c52e740", "input": null, "probe_ip": "127.0.0.1", "probe_cc": "CN", "probe_asn": "AS56040", "annotations": {"platform": "lepidopter"}, "test_helpers": {}, "report_id": "20171007T073314Z_AS56040_re2Zb27c4u8wWG2YfuXUAmUW6eXCrrotLnUmjBtlZx66JjNYmq", "measurement_uid": "0120171007df235919e72f85cee42cc424b5461d"} diff --git a/af/fastpath/fastpath/tests/data/vanilla_tor_good_new.json b/af/fastpath/fastpath/tests/data/vanilla_tor_good_new.json new file mode 100644 index 00000000..506d1fa1 --- /dev/null +++ b/af/fastpath/fastpath/tests/data/vanilla_tor_good_new.json @@ -0,0 +1 @@ +{"annotations":{"architecture":"arm64","engine_name":"ooniprobe-engine","engine_version":"3.15.2","flavor":"stableFull","network_type":"wifi","origin":"autorun","platform":"android"},"data_format_version":"0.2.0","input":null,"measurement_start_time":"2022-08-12 11:52:56","probe_asn":"AS7922","probe_cc":"US","probe_ip":"127.0.0.1","probe_network_name":"Comcast Cable Communications, LLC","report_id":"20220812T115246Z_vanillator_US_7922_n1_v8yNHvllkZNG3TVo","resolver_asn":"AS7922","resolver_ip":"76.96.24.39","resolver_network_name":"Comcast Cable Communications, LLC","software_name":"ooniprobe-android-unattended","software_version":"3.7.0","test_keys":{"bootstrap_time":10.083362131,"error":null,"failure":null,"success":true,"timeout":200,"tor_logs":["Aug 12 06:52:46.000 [notice] Bootstrapped 0% (starting): Starting","Aug 12 06:52:46.000 [notice] Bootstrapped 5% (conn): Connecting to a relay","Aug 12 06:52:46.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay","Aug 12 06:52:46.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay","Aug 12 06:52:47.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done","Aug 12 06:52:47.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection","Aug 12 06:52:47.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus","Aug 12 06:52:47.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus","Aug 12 06:52:49.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs","Aug 12 06:52:49.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors","Aug 12 06:52:50.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors","Aug 12 06:52:51.000 [notice] Bootstrapped 55% (loading_descriptors): Loading relay descriptors","Aug 12 06:52:53.000 [notice] Bootstrapped 63% (loading_descriptors): Loading relay descriptors","Aug 12 06:52:53.000 [notice] Bootstrapped 68% (loading_descriptors): Loading relay descriptors","Aug 12 06:52:53.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits","Aug 12 06:52:53.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits","Aug 12 06:52:53.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits","Aug 12 06:52:53.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits","Aug 12 06:52:53.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits","Aug 12 06:52:53.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit","Aug 12 06:52:56.000 [notice] Bootstrapped 100% (done): Done"],"tor_progress":100,"tor_progress_tag":"done","tor_progress_summary":"Done","tor_version":"0.4.6.10-dev","transport_name":"vanilla"},"test_name":"vanilla_tor","test_runtime":10.359145881,"test_start_time":"2022-08-12 11:52:45","test_version":"0.2.0"} diff --git a/af/fastpath/fastpath/tests/data/vanilla_tor_good_old.json b/af/fastpath/fastpath/tests/data/vanilla_tor_good_old.json new file mode 100644 index 00000000..57b665ae --- /dev/null +++ b/af/fastpath/fastpath/tests/data/vanilla_tor_good_old.json @@ -0,0 +1 @@ +{"test_keys": {"transport_name": "vanilla", "success": true, "tor_log": "Aug 13 01:20:13.000 [notice] Tor 0.3.4.9 (git-074ca2e0054fded1) opening new log file.\nAug 13 01:20:13.198 [warn] OpenSSL version from headers does not match the version we're running with. If you get weird crashes, that might be why. (Compiled with 1000106f: OpenSSL 1.0.1f 6 Jan 2014; running with 1000207f: OpenSSL 1.0.2g 1 Mar 2016).\nAug 13 01:20:13.231 [notice] Tor 0.3.4.9 (git-074ca2e0054fded1) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.2g, Zlib 1.2.8, Liblzma N/A, and Libzstd N/A.\nAug 13 01:20:13.231 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning\nAug 13 01:20:13.231 [notice] Configuration file \"/non-existant\" not present, using reasonable defaults.\nAug 13 01:20:13.234 [notice] Scheduler type KIST has been enabled.\nAug 13 01:20:13.234 [notice] Opening Socks listener on 127.0.0.1:2280\nAug 13 01:20:13.235 [notice] Opening Control listener on 127.0.0.1:10163\nAug 13 01:20:13.000 [notice] Bootstrapped 0%: Starting\nAug 13 01:20:13.000 [notice] Starting with guard context \"default\"\nAug 13 01:20:13.000 [notice] New control connection opened from 127.0.0.1.\nAug 13 01:20:13.000 [notice] Tor 0.3.4.9 (git-074ca2e0054fded1) opening log file.\nAug 13 01:20:13.000 [notice] Bootstrapped 5%: Connecting to directory server\nAug 13 01:20:13.000 [notice] Bootstrapped 10%: Finishing handshake with directory server\nAug 13 01:20:13.000 [notice] Bootstrapped 15%: Establishing an encrypted directory connection\nAug 13 01:20:14.000 [notice] Bootstrapped 20%: Asking for networkstatus consensus\nAug 13 01:20:14.000 [notice] Bootstrapped 25%: Loading networkstatus consensus\nAug 13 01:20:15.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.\nAug 13 01:20:15.000 [notice] Bootstrapped 40%: Loading authority key certs\nAug 13 01:20:16.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.\nAug 13 01:20:16.000 [notice] Bootstrapped 45%: Asking for relay descriptors for internal paths\nAug 13 01:20:16.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/6704, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 100% of end bw (no exits in consensus) = 0% of path bw.)\nAug 13 01:20:16.000 [notice] Bootstrapped 50%: Loading relay descriptors for internal paths\nAug 13 01:20:16.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.\nAug 13 01:20:16.000 [notice] Bootstrapped 55%: Loading relay descriptors\nAug 13 01:20:16.000 [notice] Bootstrapped 62%: Loading relay descriptors\nAug 13 01:20:17.000 [notice] Bootstrapped 72%: Loading relay descriptors\nAug 13 01:20:17.000 [notice] Bootstrapped 80%: Connecting to the Tor network\nAug 13 01:20:17.000 [notice] Bootstrapped 85%: Finishing handshake with first hop\nAug 13 01:20:17.000 [notice] Bootstrapped 90%: Establishing a Tor circuit\nAug 13 01:20:17.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.\nAug 13 01:20:17.000 [notice] Bootstrapped 100%: Done\nAug 13 01:20:17.000 [notice] Catching signal TERM, exiting cleanly.\n", "tor_progress_tag": "done", "tor_progress": 100, "timeout": 300, "error": null, "tor_version": "0.3.4.9", "tor_progress_summary": "Done"}, "software_version": "2.0.2", "test_runtime": 4.391853094100952, "test_start_time": "2020-08-13 00:00:27", "input_hashes": [], "software_name": "ooniprobe", "options": [], "data_format_version": "0.2.0", "measurement_start_time": "2020-08-13 00:20:13", "test_version": "0.1.0", "probe_city": null, "test_name": "vanilla_tor", "id": "33de92f6-e03d-4e72-b554-e27ceb6ad8e8", "input": null, "probe_ip": "127.0.0.1", "probe_cc": "IE", "probe_asn": "AS6830", "annotations": {"platform": "linux"}, "test_helpers": {}, "report_id": "20200813T000028Z_AS6830_vdHRv7BWyejAP2Gj1INiRb9qHArwaEMdxcfTvH1q8pjD24pU2G", "measurement_uid": "0120200813e619f7d08ae11ff487ebda33a984d5"} diff --git a/af/fastpath/fastpath/tests/test_unit.py b/af/fastpath/fastpath/tests/test_unit.py index 7bc19a9d..ea07af44 100644 --- a/af/fastpath/fastpath/tests/test_unit.py +++ b/af/fastpath/fastpath/tests/test_unit.py @@ -484,6 +484,24 @@ def test_score_torsf2(): } +def test_score_vanilla_tor(): + msm = loadj("vanilla_tor_bad_new") + scores = fp.score_measurement(msm) + assert scores["blocking_general"] > 0 + + msm = loadj("vanilla_tor_bad_old") + scores = fp.score_measurement(msm) + assert scores["blocking_general"] > 0 + + msm = loadj("vanilla_tor_good_new") + scores = fp.score_measurement(msm) + assert scores["blocking_general"] == 0 + + msm = loadj("vanilla_tor_good_old") + scores = fp.score_measurement(msm) + assert scores["blocking_general"] == 0 + + # # Bug tests From e0e0c7414150682b7759597d031da3702e78ad51 Mon Sep 17 00:00:00 2001 From: Federico Ceratto Date: Mon, 15 Aug 2022 16:12:36 +0100 Subject: [PATCH 3/5] Minor cleanup --- af/fastpath/fastpath/core.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/af/fastpath/fastpath/core.py b/af/fastpath/fastpath/core.py index ee2b9f90..0490dfa3 100644 --- a/af/fastpath/fastpath/core.py +++ b/af/fastpath/fastpath/core.py @@ -909,9 +909,9 @@ def score_vanilla_tor(msm): tor_logs = [] # Handle incompatibility with legacy test: # https://github.com/ooni/spec/blob/master/nettests/ts-016-vanilla-tor.md#incompatibility-with-ooniprobe-legacy - if "tor_logs" in tk and tk["tor_logs"]: + if tk.get("tor_logs"): tor_logs = tk["tor_logs"] - elif "tor_log" in tk and tk["tor_log"]: + elif tk.get("tor_log"): tor_logs = tk["tor_log"].split("\n") if len(tor_logs) == 0: From abeaf352e69a241e6582c0457b5309d2a54cbab1 Mon Sep 17 00:00:00 2001 From: Federico Ceratto Date: Mon, 15 Aug 2022 16:15:42 +0100 Subject: [PATCH 4/5] Cleanup and reflow --- af/fastpath/fastpath/core.py | 26 ++++++++++++-------------- 1 file changed, 12 insertions(+), 14 deletions(-) diff --git a/af/fastpath/fastpath/core.py b/af/fastpath/fastpath/core.py index 0490dfa3..f68385cc 100644 --- a/af/fastpath/fastpath/core.py +++ b/af/fastpath/fastpath/core.py @@ -738,12 +738,12 @@ def score_http_invalid_request_line(msm): def get_http_header(resp, header_name, case_sensitive=False): """This function returns the HTTP header(s) matching the given - header_name from the headers. The returned value is a list - given that we may have multiple keys per header. If the new - headers_list field is present in the response, we'll use - that, otherwise we'll fallback to the headers map. We perform - case insensitive header names search by default. You can yet - optionally select case sensitive comparison.""" + header_name from the headers. The returned value is a list + given that we may have multiple keys per header. If the new + headers_list field is present in the response, we'll use + that, otherwise we'll fallback to the headers map. We perform + case insensitive header names search by default. You can yet + optionally select case sensitive comparison.""" if case_sensitive == False: header_name = header_name.lower() @@ -753,7 +753,7 @@ def get_http_header(resp, header_name, case_sensitive=False): # header_list if "header_list" not in resp: headers = resp.get("headers", {}) - header_list = [[h,v] for h,v in headers.items()] + header_list = [[h, v] for h, v in headers.items()] else: headers_list = resp.get("headers_list") # TODO: unused @@ -766,6 +766,7 @@ def get_http_header(resp, header_name, case_sensitive=False): return values + @metrics.timer("score_measurement_whatsapp") def score_measurement_whatsapp(msm): """Calculate measurement scoring for Whatsapp. @@ -919,12 +920,9 @@ def score_vanilla_tor(msm): scores["accuracy"] = 0.0 return scores - if any( - [ - "Bootstrapped 100%: Done" in tl or "Bootstrapped 100% (done): Done" in tl - for tl in tor_logs - ] - ): + done1 = "Bootstrapped 100%: Done" + done2 = "Bootstrapped 100% rdone): Done" + if any((done1 in x or done2 in x) for x in tor_logs): # Success return scores @@ -1153,7 +1151,7 @@ def score_meek_fronted_requests_test(msm) -> dict: headers = resp.get("headers", {}) # headers can be a list or a dict if isinstance(headers, list): - headers = {i[0]:i[1][0] for i in headers if i} + headers = {i[0]: i[1][0] for i in headers if i} server = headers.get("Server", "") if not server.startswith("ECAcc "): scores["blocking_general"] += 0.5 From 512e03b893eecc89e108359877a6e0955d2441e0 Mon Sep 17 00:00:00 2001 From: Federico Ceratto Date: Mon, 15 Aug 2022 16:17:10 +0100 Subject: [PATCH 5/5] Bump version --- af/fastpath/debian/changelog | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/af/fastpath/debian/changelog b/af/fastpath/debian/changelog index 7f2c09e1..0481b375 100644 --- a/af/fastpath/debian/changelog +++ b/af/fastpath/debian/changelog @@ -1,3 +1,9 @@ +fastpath (0.59) unstable; urgency=medium + + * Fix vanilla_tor https://github.com/ooni/backend/issues/608 + + -- Federico Ceratto Mon, 15 Aug 2022 16:17:07 +0100 + fastpath (0.58) unstable; urgency=medium * Add DNS fingerprints for Iran