search

ooni / probe

OONI Probe network measurement tool for detecting internet censorship
https://ooni.org/install
BSD 3-Clause "New" or "Revised" License
764 stars 142 forks source link

Unable to upload result that was not uploaded #1302

Closed xhdix closed 3 years ago

xhdix commented 3 years ago

Reported by a user in Twitter:

image

image

image

Specifications

lorenzoPrimi commented 3 years ago

Hi @xhdix we need the log to be able to identify the issue, as it it there is nothing I can do.

xhdix commented 3 years ago

Hi @lorenzoPrimi Unfortunately, In the case tested by myself, DISPLAY FAILURE LOG is empty.

xhdix commented 3 years ago

I do not know if I had the right strategy for reproducing it. Because it may be a different matter.

D/MK_EVENT: {"key":"status.progress","value":{"message":"psiphon experiment running","percentage":1.0000000000000009}}
D/TestAsyncTask: TestAsyncTask.PRG 100
D/MK_EVENT: {"key":"status.progress","value":{"message":"psiphon experiment complete","percentage":1}}
D/MK_EVENT: {"key":"log","value":{"log_level":"WARNING","message":"cannot start tunnel: clientlib.StartTunnel#285: tunnel start produced error: clientlib.StartTunnel.func3#271: controller.Run exited unexpectedly"}}
D/MK_EVENT: {"key":"failure.measurement","value":{"failure":"unknown_failure: clientlib.StartTunnel#285: tunnel start produced error: clientlib.StartTunnel.func3#271: controller.Run exited unexpectedly","idx":0,"input":""}}
W/UNUSED_KEY: failure.measurement
D/MK_EVENT: {"key":"measurement","value":{"idx":0,"input":"","json_str":"{\"annotations\":{\"assets_version\":\"20201112191431\",\"engine_name\":\"ooniprobe-engine\",\"engine_version\":\"0.20.2\",\"flavor\":\"devFull\",\"network_type\":\"wifi\",\"platform\":\"android\"},\"data_format_version\":\"0.2.0\",\"extensions\":{\"dnst\":0,\"httpt\":0,\"netevents\":0,\"tlshandshake\":0,\"tunnel\":0},\"input\":null,\"measurement_start_time\":\"2020-12-04 17:35:11\",\"probe_asn\":\"AS58224\",\"probe_cc\":\"IR\",\"probe_ip\":\"127.0.0.1\",\"probe_network_name\":\"Iran Telecommunication Company PJS\",\"report_id\":\"20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4\",\"resolver_asn\":\"AS20857\",\"resolver_ip\":\"127.0.0.2\",\"resolver_network_name\":\"Transip B.V.\",\"software_name\":\"ooniprobe-android-dev-debug\",\"software_version\":\"2020.12.04-17\",\"test_keys\":{\"agent\":\"redirect\",\"failed_operation\":\"top_level\",\"failure\":\"unknown_failure: clientlib.StartTunnel#285: tunnel start produced error: clientlib.StartTunnel.func3#271: controller.Run exited unexpectedly\",\"network_events\":null,\"queries\":null,\"requests\":null,\"tcp_connect\":null,\"tls_handshakes\":null,\"tunnel\":\"psiphon\",\"max_runtime\":60},\"test_name\":\"psiphon\",\"test_runtime\":60.015982112,\"test_start_time\":\"2020-12-04 17:35:02\",\"test_version\":\"0.4.0\"}"}}
D/TestAsyncTask: TestAsyncTask.PRG 100
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE (`id`=89) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
    Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Submitting measurement... please, be patient"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: request body: 1184 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: POST"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps1.ooni.io/report/20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://ps1.ooni.io/report/20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/json"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps1.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 77"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: nginx/1.14.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:36:13 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: response body: 77 bytes"}}
D/MK_EVENT: {"key":"status.measurement_submission","value":{"idx":0,"input":"","json_str":"{\"annotations\":{\"assets_version\":\"20201112191431\",\"engine_name\":\"ooniprobe-engine\",\"engine_version\":\"0.20.2\",\"flavor\":\"devFull\",\"network_type\":\"wifi\",\"platform\":\"android\"},\"data_format_version\":\"0.2.0\",\"extensions\":{\"dnst\":0,\"httpt\":0,\"netevents\":0,\"tlshandshake\":0,\"tunnel\":0},\"input\":null,\"measurement_start_time\":\"2020-12-04 17:35:11\",\"probe_asn\":\"AS58224\",\"probe_cc\":\"IR\",\"probe_ip\":\"127.0.0.1\",\"probe_network_name\":\"Iran Telecommunication Company PJS\",\"report_id\":\"20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4\",\"resolver_asn\":\"AS20857\",\"resolver_ip\":\"127.0.0.2\",\"resolver_network_name\":\"Transip B.V.\",\"software_name\":\"ooniprobe-android-dev-debug\",\"software_version\":\"2020.12.04-17\",\"test_keys\":{\"agent\":\"redirect\",\"failed_operation\":\"top_level\",\"failure\":\"unknown_failure: clientlib.StartTunnel#285: tunnel start produced error: clientlib.StartTunnel.func3#271: controller.Run exited unexpectedly\",\"network_events\":null,\"queries\":null,\"requests\":null,\"tcp_connect\":null,\"tls_handshakes\":null,\"tunnel\":\"psiphon\",\"max_runtime\":60},\"test_name\":\"psiphon\",\"test_runtime\":60.015982112,\"test_start_time\":\"2020-12-04 17:35:02\",\"test_version\":\"0.4.0\"}"}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE (`id`=89) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"status.measurement_done","value":{"idx":0,"input":""}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE (`id`=89) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Closing report... please, be patient"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: request body: 2 bytes"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: POST"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps1.ooni.io/report/20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4/close"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://ps1.ooni.io/report/20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4/close"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/json"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps1.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: nginx/1.14.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:36:13 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 3"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cache-Control: max-age=3600"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: response body: 3 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"sessionresolver: failure rate: primary: 1/4; fallback: 0/1"}}
D/MK_EVENT: {"key":"status.end","value":{"downloaded_kb":0.7060546875,"failure":"","uploaded_kb":1.93359375}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"task_terminated","value":{}}
D/TestAsyncTask: run next stuite: circumvention test:tor
D/MK_EVENT: {"key":"status.started","value":{}}
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Looking up OONI backends... please, be patient"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: GET"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps1.ooni.io/api/v1/test-helpers"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e GET https://ps1.ooni.io/api/v1/test-helpers"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps1.ooni.io"}}
D/TestAsyncTask: TestAsyncTask.RUN
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com... ([104.16.133.229 104.16.132.229 2606:4700::6810:85e5 2606:4700::6810:84e5], \u003cnil\u003e) in 3.508385ms"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"dial 104.16.133.229:443/tcp..."}}
D/TestAsyncTask: TestAsyncTask.PRG 100
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 104.16.133.229:443/tcp... \u003cnil\u003e in 663.636562ms"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=cloudflare.com next=[h2 http/1.1]}..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=cloudflare.com next=[h2 http/1.1]}... \u003cnil\u003e in 726.263177ms {next=h2 cipher=TLS_AES_128_GCM_SHA256 v=TLSv1.3}"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Request-Id: 06d06c8304000096b085364000000001"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Expect-Ct: max-age=604800, report-uri=\"https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct\""}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: cloudflare"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Ray: 5fc749e4dd1696b0-FRA"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:36:16 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 468"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 468"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Request-Id: 06d06c85d0000096b08c3eb000000001"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Expect-Ct: max-age=604800, report-uri=\"https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct\""}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: cloudflare"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Ray: 5fc749e9494a96b0-FRA"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:36:16 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp... \u003cnil\u003e in 740.693229ms"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps1.ooni.io next=[h2 http/1.1]}..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps1.ooni.io next=[h2 http/1.1]}... \u003cnil\u003e in 914.268541ms {next=h2 cipher=TLS_AES_128_GCM_SHA256 v=TLSv1.3}"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c unknown_failure: read tcp [scrubbed]-\u003e[scrubbed]: read: connection timed out"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"probe services: {Address:https://ps1.ooni.io Type:https Front:}: Get \"https://ps1.ooni.io/api/v1/test-helpers\": unknown_failure: read tcp [scrubbed]-\u003e[scrubbed]: read: connection timed out 2m21.668024581s"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: GET"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps2.ooni.io/api/v1/test-helpers"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e GET https://ps2.ooni.io/api/v1/test-helpers"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps2.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com..."}}
    {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com... ([104.16.133.229 104.16.132.229 2606:4700::6810:85e5 2606:4700::6810:84e5], \u003cnil\u003e) in 9.17ms"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 104.16.133.229:443/tcp..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 104.16.133.229:443/tcp... \u003cnil\u003e in 1.659064791s"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=cloudflare.com next=[h2 http/1.1]}..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=cloudflare.com next=[h2 http/1.1]}... \u003cnil\u003e in 402.802552ms {next=h2 cipher=TLS_AES_128_GCM_SHA256 v=TLSv1.3}"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: cloudflare"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Ray: 5fc74d5cf92a177a-FRA"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:38:38 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 468"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Request-Id: 06d06eae1d0000177a66847000000001"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Expect-Ct: max-age=604800, report-uri=\"https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct\""}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Request-Id: 06d06eb0130000177a159b8000000001"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Expect-Ct: max-age=604800, report-uri=\"https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct\""}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: cloudflare"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cf-Ray: 5fc74d601a1c177a-FRA"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:38:38 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 468"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp... \u003cnil\u003e in 526.641615ms"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps2.ooni.io next=[h2 http/1.1]}..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps2.ooni.io next=[h2 http/1.1]}... \u003cnil\u003e in 693.553385ms {next=h2 cipher=TLS_AES_128_GCM_SHA256 v=TLSv1.3}"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c X-Cache-Status: HIT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c X-Cache-Status: HIT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: nginx/1.14.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:38:42 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 1538"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cache-Control: max-age=3600"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c X-Ratelimit-Remaining: 3999"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: response body: 1538 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"probe services: {Address:https://ps2.ooni.io Type:https Front:}: \u003cnil\u003e 6.765590778s"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"session: using probe services: {Address:https://ps2.ooni.io Type:https Front:}"}}
D/MK_EVENT: {"key":"status.progress","value":{"message":"contacted bouncer","percentage":0.1}}
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Looking up your location... please, be patient"}}
D/TestAsyncTask: TestAsyncTask.PRG 110
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"iplookup: using stun_ekiga"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"STUNIPLookup: start using stun.ekiga.net:3478"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"iplookup: IP: 217.*.*.*"}}
D/MK_EVENT: {"key":"status.progress","value":{"message":"geoip lookup","percentage":0.2}}
D/TestAsyncTask: TestAsyncTask.PRG 120
D/MK_EVENT: {"key":"status.progress","value":{"message":"resolver lookup","percentage":0.3}}
D/MK_EVENT: {"key":"status.geoip_lookup","value":{"probe_asn":"AS58224","probe_cc":"IR","probe_ip":"217.*.*.*","probe_network_name":"Iran Telecommunication Company PJS"}}
D/MK_EVENT: {"key":"status.resolver_lookup","value":{"resolver_asn":"AS20857","resolver_ip":"136.144.215.158","resolver_network_name":"Transip B.V."}}
W/UNUSED_KEY: status.resolver_lookup
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Opening report... please, be patient"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: request body: 247 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: POST"}}
D/TestAsyncTask: TestAsyncTask.PRG 130
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps2.ooni.io/report"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://ps2.ooni.io/report"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps2.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: nginx/1.14.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:38:45 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 157"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: response body: 157 bytes"}}
D/MK_EVENT: {"key":"status.progress","value":{"message":"open report","percentage":0.4}}
D/MK_EVENT: {"key":"status.report_create","value":{"report_id":"20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn"}}
    {"key":"log","value":{"log_level":"INFO","message":"Starting measurement with index 0"}}
D/MK_EVENT: {"key":"status.measurement_start","value":{"idx":0,"input":""}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: GET"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps2.ooni.io/api/v1/test-list/tor-targets?country_code=IR"}}
D/TestAsyncTask: TestAsyncTask.PRG 140
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e GET https://ps2.ooni.io/api/v1/test-list/tor-targets?country_code=IR"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps2.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Authorization: Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJyb2xlIjoiZGV2aWNlIiwidXNlciI6IjdhMzA3ZGIxLWNjZTQtNDY5NS05ODI5LTM1NjA3ODZiMDlmMSIsImV4cCI6MTYwNzEwNjkxNCwiaWF0IjoxNjA3MTAzMzE0fQ.l0cTwFIvLB_RLjN2mJOiB4WcGveUWGMIRVBVLtFtbrs"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c context deadline exceeded"}}
D/MK_EVENT: {"key":"failure.measurement","value":{"failure":"Get \"https://ps2.ooni.io/api/v1/test-list/tor-targets?country_code=IR\": context deadline exceeded","idx":0,"input":""}}
W/UNUSED_KEY: failure.measurement
D/MK_EVENT: {"key":"measurement","value":{"idx":0,"input":"","json_str":"{\"annotations\":{\"assets_version\":\"20201112191431\",\"engine_name\":\"ooniprobe-engine\",\"engine_version\":\"0.20.2\",\"flavor\":\"devFull\",\"network_type\":\"wifi\",\"platform\":\"android\"},\"data_format_version\":\"0.2.0\",\"input\":null,\"measurement_start_time\":\"2020-12-04 17:38:45\",\"probe_asn\":\"AS58224\",\"probe_cc\":\"IR\",\"probe_ip\":\"127.0.0.1\",\"probe_network_name\":\"Iran Telecommunication Company PJS\",\"report_id\":\"20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn\",\"resolver_asn\":\"AS20857\",\"resolver_ip\":\"127.0.0.2\",\"resolver_network_name\":\"Transip B.V.\",\"software_name\":\"ooniprobe-android-dev-debug\",\"software_version\":\"2020.12.04-17\",\"test_keys\":null,\"test_name\":\"tor\",\"test_runtime\":15.002020932,\"test_start_time\":\"2020-12-04 17:38:45\",\"test_version\":\"0.2.0\"}"}}
W/System.err: java.lang.NullPointerException: Attempt to read from field 'java.lang.Long org.openobservatory.ooniprobe.model.jsonresult.TestKeys.dir_port_accessible' on a null object reference
W/System.err:     at org.openobservatory.ooniprobe.test.test.Tor.onEntry(Tor.java:31)
W/System.err:     at org.openobservatory.ooniprobe.test.test.AbstractTest.run(AbstractTest.java:127)
W/System.err:     at org.openobservatory.ooniprobe.test.test.Tor.run(Tor.java:26)
W/System.err:     at org.openobservatory.ooniprobe.test.TestAsyncTask.runTest(TestAsyncTask.java:85)
W/System.err:     at org.openobservatory.ooniprobe.test.TestAsyncTask.doInBackground(TestAsyncTask.java:69)
W/System.err:     at org.openobservatory.ooniprobe.test.TestAsyncTask.doInBackground(TestAsyncTask.java:33)
W/System.err:     at android.os.AsyncTask$2.call(AsyncTask.java:333)
W/System.err:     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
W/System.err:     at java.lang.Thread.run(Thread.java:764)
I/y.ooniprobe.de: Waiting for a blocking GC ProfileSaver
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Submitting measurement... please, be patient"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"httpx: request body: 770 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: POST"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps2.ooni.io/report/20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://ps2.ooni.io/report/20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/json"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps2.ooni.io"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
I/y.ooniprobe.de: Background concurrent copying GC freed 85395(8MB) AllocSpace objects, 0(0B) LOS objects, 49% free, 8MB/17MB, paused 189us total 121.096ms
I/y.ooniprobe.de: WaitForGcToComplete blocked ProfileSaver on HeapTrim for 78.682ms
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c unknown_failure: read tcp [scrubbed]-\u003e[scrubbed]: read: connection timed out"}}
D/MK_EVENT: {"key":"failure.measurement_submission","value":{"failure":"Post \"https://ps2.ooni.io/report/20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn\": unknown_failure: read tcp [scrubbed]-\u003e[scrubbed]: read: connection timed out","idx":0,"input":"","json_str":"{\"annotations\":{\"assets_version\":\"20201112191431\",\"engine_name\":\"ooniprobe-engine\",\"engine_version\":\"0.20.2\",\"flavor\":\"devFull\",\"network_type\":\"wifi\",\"platform\":\"android\"},\"data_format_version\":\"0.2.0\",\"input\":null,\"measurement_start_time\":\"2020-12-04 17:38:45\",\"probe_asn\":\"AS58224\",\"probe_cc\":\"IR\",\"probe_ip\":\"127.0.0.1\",\"probe_network_name\":\"Iran Telecommunication Company PJS\",\"report_id\":\"20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn\",\"resolver_asn\":\"AS20857\",\"resolver_ip\":\"127.0.0.2\",\"resolver_network_name\":\"Transip B.V.\",\"software_name\":\"ooniprobe-android-dev-debug\",\"software_version\":\"2020.12.04-17\",\"test_keys\":null,\"test_name\":\"tor\",\"test_runtime\":15.002020932,\"test_start_time\":\"2020-12-04 17:38:45\",\"test_version\":\"0.2.0\"}"}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE (`id`=90) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"status.measurement_done","value":{"idx":0,"input":""}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE (`id`=90) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"Closing report... please, be patient"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: request body: 2 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: method: POST"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"httpx: URL: https://ps2.ooni.io/report/20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn/close"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://ps2.ooni.io/report/20201204T173845Z_tor_IR_58224_n1_wlTRn8hAiQOQJsAn/close"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: ooniprobe-android-dev-debug/2020.12.04-17 ooniprobe-engine/0.20.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: ps2.ooni.io"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c context deadline exceeded"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e POST https://cloudflare.com/dns-query"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.111 Safari/537.36"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Content-Type: application/dns-message"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e Host: dns.cloudflare.com"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003e"}}
    {"key":"log","value":{"log_level":"DEBUG","message":"\u003c context deadline exceeded"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"resolve cloudflare.com... ([], generic_timeout_error) in 4.001318541s"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp..."}}
I/y.ooniprobe.de: Background concurrent copying GC freed 82733(8MB) AllocSpace objects, 7(268KB) LOS objects, 49% free, 8MB/17MB, paused 326us total 122.846ms
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"dial 142.93.237.101:443/tcp... \u003cnil\u003e in 869.740885ms"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps2.ooni.io next=[h2 http/1.1]}..."}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"tls {sni=ps2.ooni.io next=[h2 http/1.1]}... \u003cnil\u003e in 1.032764896s {next=h2 cipher=TLS_AES_128_GCM_SHA256 v=TLSv1.3}"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c 200"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Length: 3"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Cache-Control: max-age=3600"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Access-Control-Allow-Origin: *"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Server: nginx/1.14.2"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Date: Fri, 04 Dec 2020 17:42:02 GMT"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c Content-Type: application/json"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"\u003c"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"DEBUG","message":"httpx: response body: 3 bytes"}}
D/MK_EVENT: {"key":"log","value":{"log_level":"INFO","message":"sessionresolver: failure rate: primary: 1/3; fallback: 0/1"}}
D/MK_EVENT: {"key":"status.end","value":{"downloaded_kb":0.4794921875,"failure":"","uploaded_kb":1.517578125}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
D/MK_EVENT: {"key":"task_terminated","value":{}}
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result`
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network`
V/FlowLog: Executing query: SELECT SUM(`data_usage_up`) FROM `Result`
V/FlowLog: Executing query: SELECT SUM(`data_usage_down`) FROM `Result`
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) 
V/FlowLog: Executing query: SELECT * FROM `Result` ORDER BY `start_time` DESC 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=2 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=2 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=1 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=1 LIMIT 1 
I/chatty: uid=10175(org.openobservatory.ooniprobe.dev) identical 1 line

re-upload:

W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@28facf8
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Result` WHERE (`id`=9) 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Network` WHERE (`id`=3) 
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 ORDER BY `id` ASC 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) AND `result_id`=9 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 ORDER BY `start_time` ASC LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 ORDER BY `start_time` DESC LIMIT 1 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 AND `is_failed`=0 AND `is_anomaly`=1 
V/FlowLog: Executing query: SELECT COUNT(*) FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 AND `is_failed`=0 AND `is_anomaly`=0 
D/OpenGLRenderer: endAllActiveAnimators on 0x713e466200 (LinearLayout) with handle 0x713f47c6e0
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@4d92545
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `id`=89 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
I/AppCompatViewInflater: app:theme is now deprecated. Please move to using android:theme instead.
D/OkHttp: --> GET https://api.ooni.io/api/_/check_report_id?report_id=20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4
    --> END GET
W/StaticLayout: maxLineHeight should not be -1.  maxLines:1 lineCount:1
I/chatty: uid=10175(org.openobservatory.ooniprobe.dev) identical 1 line
W/StaticLayout: maxLineHeight should not be -1.  maxLines:1 lineCount:1
D/OpenGLRenderer: endAllActiveAnimators on 0x713e56ad00 (AppCompatTextView) with handle 0x7140881560
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 ORDER BY `id` ASC 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) AND `result_id`=9 
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@4038756
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `id`=89 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
I/AppCompatViewInflater: app:theme is now deprecated. Please move to using android:theme instead.
D/OkHttp: --> GET https://api.ooni.io/api/_/check_report_id?report_id=20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4
    --> END GET
W/StaticLayout: maxLineHeight should not be -1.  maxLines:1 lineCount:1
I/chatty: uid=10175(org.openobservatory.ooniprobe.dev) identical 1 line
W/StaticLayout: maxLineHeight should not be -1.  maxLines:1 lineCount:1
D/OpenGLRenderer: endAllActiveAnimators on 0x713e07fd00 (AppCompatTextView) with handle 0x713e3ff4e0
D/OkHttp: <-- 200 https://api.ooni.io/api/_/check_report_id?report_id=20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4 (6462ms)
    server: nginx/1.14.2
    date: Fri, 04 Dec 2020 17:42:31 GMT
D/OkHttp: content-type: application/json
    content-length: 31
    cache-control: max-age=5.0
    x-ratelimit-remaining: 3999
    access-control-allow-origin: *
    x-cache-status: MISS
    x-cache-status: MISS
D/OkHttp: {
      "found": true, 
      "v": 0
    }
    <-- END HTTP (31-byte body)
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE (`is_uploaded`=1 OR `report_id` IS NOT NULL ) AND `report_id`='20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4' 
D/OkHttp: <-- 200 https://api.ooni.io/api/_/check_report_id?report_id=20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4 (1213ms)
D/OkHttp: server: nginx/1.14.2
    date: Fri, 04 Dec 2020 17:42:32 GMT
    content-type: application/json
    content-length: 31
    cache-control: max-age=5.0
    x-ratelimit-remaining: 3999
    access-control-allow-origin: *
    x-cache-status: MISS
D/OkHttp: x-cache-status: MISS
D/OkHttp: {
      "found": true, 
      "v": 0
D/OkHttp: }
    <-- END HTTP (31-byte body)
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE (`is_uploaded`=1 OR `report_id` IS NOT NULL ) AND `report_id`='20201204T173512Z_psiphon_IR_58224_n1_8XiFOHSHco2NVas4' 
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@5a1fee8
D/OpenGLRenderer: endAllActiveAnimators on 0x713e5ea000 (MenuPopupWindow$MenuDropDownListView) with handle 0x713dea62c0
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 ORDER BY `id` ASC 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) AND `result_id`=9 
I/y.ooniprobe.de: Background concurrent copying GC freed 138623(9MB) AllocSpace objects, 32(992KB) LOS objects, 49% free, 10MB/20MB, paused 852us total 154.864ms
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) AND `result_id`=9 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
W/System.err: java.io.FileNotFoundException: File '/data/user/0/org.openobservatory.ooniprobe.dev/files/Measurement/90_tor.json' does not exist
W/System.err:     at org.apache.commons.io.FileUtils.openInputStream(FileUtils.java:297)
        at org.apache.commons.io.FileUtils.readFileToString(FileUtils.java:1805)
        at org.openobservatory.ooniprobe.common.ResubmitTask.perform(ResubmitTask.java:49)
        at org.openobservatory.ooniprobe.common.ResubmitTask.doInBackground(ResubmitTask.java:114)
W/System.err:     at org.openobservatory.ooniprobe.common.ResubmitTask.doInBackground(ResubmitTask.java:28)
        at android.os.AsyncTask$2.call(AsyncTask.java:333)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
I/DpmTcmClient: RegisterTcmMonitor from: $Proxy0
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Result` WHERE `id`=9 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
    Executing query: SELECT * FROM `Measurement` WHERE `result_id`=9 AND `is_rerun`=0 AND `is_done`=1 ORDER BY `id` ASC 
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `is_rerun`=0 AND `is_done`=1 AND (`is_uploaded`=0 OR `report_id` IS NULL ) AND `result_id`=9 
I/y.ooniprobe.de: Background concurrent copying GC freed 131818(8MB) AllocSpace objects, 70(2MB) LOS objects, 49% free, 10MB/20MB, paused 588us total 126.616ms
D/OpenGLRenderer: endAllActiveAnimators on 0x713d830c00 (MaterialButtonBackgroundDrawable) with handle 0x713f47cc40

Tap on the result:

W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@a09edea
V/FlowLog: Executing query: SELECT * FROM `Measurement` WHERE `id`=90 LIMIT 1 
V/FlowLog: Executing query: SELECT * FROM `Network` WHERE `id`=3 LIMIT 1 
I/AppCompatViewInflater: app:theme is now deprecated. Please move to using android:theme instead.
D/AndroidRuntime: Shutting down VM
E/AndroidRuntime: FATAL EXCEPTION: main
    Process: org.openobservatory.ooniprobe.dev, PID: 25419
    java.lang.NullPointerException: Attempt to invoke virtual method 'java.lang.String org.openobservatory.ooniprobe.model.jsonresult.TestKeys.getBridges(android.content.Context)' on a null object reference
        at org.openobservatory.ooniprobe.fragment.measurement.TorFragment.onCreateView(TorFragment.java:45)
        at androidx.fragment.app.Fragment.performCreateView(Fragment.java:2600)
        at androidx.fragment.app.FragmentManagerImpl.moveToState(FragmentManagerImpl.java:881)
        at androidx.fragment.app.FragmentManagerImpl.moveFragmentToExpectedState(FragmentManagerImpl.java:1238)
        at androidx.fragment.app.FragmentManagerImpl.moveToState(FragmentManagerImpl.java:1303)
        at androidx.fragment.app.BackStackRecord.executeOps(BackStackRecord.java:439)
        at androidx.fragment.app.FragmentManagerImpl.executeOps(FragmentManagerImpl.java:2079)
        at androidx.fragment.app.FragmentManagerImpl.executeOpsTogether(FragmentManagerImpl.java:1869)
        at androidx.fragment.app.FragmentManagerImpl.removeRedundantOperationsAndExecute(FragmentManagerImpl.java:1824)
        at androidx.fragment.app.FragmentManagerImpl.execPendingActions(FragmentManagerImpl.java:1727)
        at androidx.fragment.app.FragmentManagerImpl.dispatchStateChange(FragmentManagerImpl.java:2663)
        at androidx.fragment.app.FragmentManagerImpl.dispatchActivityCreated(FragmentManagerImpl.java:2613)
        at androidx.fragment.app.FragmentController.dispatchActivityCreated(FragmentController.java:246)
        at androidx.fragment.app.FragmentActivity.onStart(FragmentActivity.java:542)
        at androidx.appcompat.app.AppCompatActivity.onStart(AppCompatActivity.java:210)
        at android.app.Instrumentation.callActivityOnStart(Instrumentation.java:1392)
        at android.app.Activity.performStart(Activity.java:7161)
        at android.app.ActivityThread.handleStartActivity(ActivityThread.java:2938)
        at android.app.servertransaction.TransactionExecutor.performLifecycleSequence(TransactionExecutor.java:186)
        at android.app.servertransaction.TransactionExecutor.cycleToPath(TransactionExecutor.java:171)
        at android.app.servertransaction.TransactionExecutor.executeLifecycleState(TransactionExecutor.java:142)
        at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:70)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1809)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6692)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
I/Process: Sending signal. PID: 25419 SIG: 9
Disconnected from the target VM, address: 'localhost:11760', transport: 'socket'
bassosimone commented 3 years ago

Thank you @xhdix for providing very detailed information. It seems to me there is a bunch of issues to unpack in these logs and it's clear to me some actions to fix should be taken in probe-engine and some in probe-android. 🙏

lorenzoPrimi commented 3 years ago

Possible duplicate of https://github.com/ooni/probe/issues/1345

lorenzoPrimi commented 3 years ago

After some research, I concluded that the problem(s) here are :