Opened 7 years ago

Closed 6 years ago

#8552 closed defect (fixed)

ooni: reporter hangs at the end of a test indefinitely and after SIGINT raises OONIBReportCreationError

Reported by: isis Owned by: hellais
Priority: Medium Milestone:
Component: Archived/Ooni Version:
Severity: Keywords: ooni, bugreport
Cc: hellais, ioerror, aagbsn, isis Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

The reporter hangs indefinitely, until given a SIGINT, and then it raises an OONIBReportCreationError.

(ooni)?!isis?wintermute:~/code/torproject/ooni-probe ? s bin/ooniprobe nettests/experimental/bridge_reachability/echo.py -f private/lists/ping-me.list
Log opened.
[D] No test deck detected
[!] pypcap or dnet not installed. Certain tests may not work.
.
Sent 1 packets.
Starting Tor...
[D] Setting control port as 55051
[D] Setting SOCKS port as 55050
[D] 10%: Finishing handshake with directory server
[D] 15%: Establishing an encrypted directory connection
[D] 20%: Asking for networkstatus consensus
[D] 25%: Loading networkstatus consensus
[D] 40%: Loading authority key certs
[D] 45%: Asking for relay descriptors
[D] 80%: Connecting to the Tor network
[D] 85%: Finishing handshake with first hop
[D] 90%: Establishing a Tor circuit
[D] 100%: Done
[D] Building a TorState
Successfully bootstrapped Tor
[D] We now have the following circuits:
[D]  * <Circuit 1 BUILT [193.23.244.244] for GENERAL>
[D]  * <Circuit 2 BUILT [154.35.32.5] for GENERAL>
[D]  * <Circuit 3 BUILT [192.95.14.16] for GENERAL>
[D]  * <Circuit 4 BUILT [109.163.233.205] for GENERAL>
[D]  * <Circuit 5 BUILT [95.27.246.76] for GENERAL>
[D]  * <Circuit 6 BUILT [93.215.73.65] for GENERAL>
[D]  * <Circuit 7 BUILT [173.254.216.68] for GENERAL>
[D]  * <Circuit 8 BUILT [80.237.226.74] for GENERAL>
[D]  * <Circuit 9 BUILT [67.180.227.177] for GENERAL>
[D]  * <Circuit 10 BUILT [108.46.50.99] for GENERAL>
[D]  * <Circuit 11 BUILT [37.221.170.49] for GENERAL>
[D]  * <Circuit 12 BUILT [46.59.212.22] for GENERAL>
[D]  * <Circuit 13 BUILT [96.47.226.20] for GENERAL>
[D]  * <Circuit 14 BUILT [91.121.178.161] for GENERAL>
[D]  * <Circuit 15 BUILT [204.11.50.131] for GENERAL>
[D]  * <Circuit 16 BUILT [95.211.213.148] for GENERAL>
[D]  * <Circuit 17 BUILT [31.172.30.4] for GENERAL>
[D]  * <Circuit 18 BUILT [93.182.129.82] for GENERAL>
[D]  * <Circuit 19 BUILT [178.18.19.163] for GENERAL>
[D]  * <Circuit 20 BUILT [193.11.164.242] for GENERAL>
[D]  * <Circuit 21 BUILT [96.47.226.21] for GENERAL>
[D]  * <Circuit 22 BUILT [217.199.162.162] for GENERAL>
[D]  * <Circuit 23 BUILT [37.9.170.229] for GENERAL>
[D]  * <Circuit 24 BUILT [199.48.147.36] for GENERAL>
[D]  * <Circuit 25 BUILT [31.31.75.50] for GENERAL>
[D]  * <Circuit 26 BUILT [95.211.213.146] for GENERAL>
[D]  * <Circuit 27 BUILT [86.176.177.2] for GENERAL>
[D]  * <Circuit 28 BUILT [37.46.194.6] for GENERAL>
[D]  * <Circuit 29 EXTENDED [78.142.142.246 109.163.233.205] for GENERAL>
[D]  * <Circuit 30 EXTENDED [78.142.142.246 96.47.226.21] for GENERAL>
[D]  * <Circuit 31 EXTENDED [195.191.16.63 96.47.226.21] for GENERAL>
[D]  * <Circuit 32 BUILT [195.191.16.63 96.47.226.21 204.11.50.131] for GENERAL>
[D] Obtained our IP address from a Tor Relay 38.111.11.2
[D] adding callback for startNetTest
[D] Creating ./report-icmp-2013-03-21T073400Z.yamloo
[D] Writing report with YAML reporter
Reporting httpo://nkvphnp3p6agi5qq.onion/report
[D] Sending {"software_name": "ooniprobe", "software_version": "0.0.10", "content": "---\noptions:\n  collector: null\n  help: 0\n  logfile: null\n  no-default
-reporter: 0\n  parallelism: '10'\n  pcapfile: null\n  reportfile: null\n  resume: 0\n  subargs: [-f, private/lists/ping-me.list]\n  test: nettests/experimenta
l/bridge_reachability/echo.py\n  testdeck: null\nprobe_asn: AS0\nprobe_cc: null\nprobe_ip: 127.0.0.1\nsoftware_name: ooniprobe\nsoftware_version: 0.0.10\nstart
_time: 1363851240.0\ntest_name: icmp\ntest_version: 0.0.5\n...\n", "test_version": "0.0.5", "test_name": "icmp", "probe_asn": "AS0"}
Creating report with OONIB Reporter. Please be patient.
This may take up to 1-2 minutes...
[D] Reporters created: [<Deferred at 0x2ea6368 current result: <ooni.reporter.YAMLReporter object at 0x3740650>>, <Deferred at 0x2f57368>]
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Scapy factoring not set, registering it.
[D] Building packets...
[D] Sending...
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x4227450>
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Building packets...
[D] Sending...
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x42275d0>
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Building packets...
[D] Sending...
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x4227910>
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Building packets...
[D] Sending...
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x4227d90>
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Building packets...
[D] Sending...
[D] Sending...                                                                                                                                         [10/210]
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x405c250>
[D] Running <class 'echo.ICMPTest'> test_icmp
[D] Building packets...
[D] Sending...
[D] Using sending with hash <method-wrapper '__hash__' of ScapySender object at 0x405c6d0>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x4227310>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4231050>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x2eb2390>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x4227750>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227310>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227350>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x4227fd0>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227750>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x42278d0>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x4227510>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227450>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4231250>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x405c490>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227590>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4227510>
Successfully completed measurement: <ooni.tasks.Measurement object at 0x4227c10>
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x42310d0>
[D] Writing report with YAML reporter
[D] Adding report entry task <ooni.tasks.ReportEntry object at 0x4231350>
^CReceived SIGINT, shutting down.
Traceback (most recent call last):
  File "/home/isis/code/torproject/ooni-probe/ooni/reporter.py", line 338, in createReport
    bodyProducer=bodyProducer)
ResponseNeverReceived: [<twisted.python.failure.Failure <class 'twisted.internet.error.ConnectionLost'>>]
Unhandled error in Deferred:
Unhandled Error
Traceback (most recent call last):
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 397, in errback
    self._startRunCallbacks(fail)
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 464, in _startRunCallbacks
    self._runCallbacks()
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 551, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1101, in gotResult
    _inlineCallbacks(r, g, deferred)
--- <exception caught here> ---
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1043, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/home/isis/.virtualenvs/ooni/local/lib/python2.7/site-packages/twisted/python/failure.py", line 382, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/home/isis/code/torproject/ooni-probe/ooni/reporter.py", line 345, in createReport
    raise OONIBReportCreationError
ooni.reporter.OONIBReportCreationError:

Main loop terminated.

Child Tickets

Change History (3)

comment:1 Changed 7 years ago by isis

It hangs with other tests as well:

?!isis?wintermute:~/code/torproject/ooni-probe ? cat >> private/tickets/txtorcon-no-datadir
(ooni)?!isis?wintermute:~/code/torproject/ooni-probe ? s bin/ooniprobe nettests/blocking/dnsconsistency.py -f private/lists/ping-me.list
Log opened.
[D] No test deck detected
[D] Checking if backend is present
[D] Checking if file is present
Starting Tor...
[D] Setting control port as 55051
[D] Setting SOCKS port as 55050
[D] 10%: Finishing handshake with directory server
[D] 15%: Establishing an encrypted directory connection
[D] 20%: Asking for networkstatus consensus
[D] 25%: Loading networkstatus consensus
[D] 40%: Loading authority key certs
[D] 45%: Asking for relay descriptors
[D] 80%: Connecting to the Tor network
[D] 85%: Finishing handshake with first hop
[D] 90%: Establishing a Tor circuit
[D] 100%: Done
[D] Building a TorState
Successfully bootstrapped Tor
[D] We now have the following circuits:
[D]  * <Circuit 1 BUILT [212.112.245.170] for GENERAL>
[D]  * <Circuit 2 BUILT [193.23.244.244] for GENERAL>
[D]  * <Circuit 3 BUILT [96.47.226.21] for GENERAL>
[D]  * <Circuit 4 BUILT [212.232.24.57] for GENERAL>
[D]  * <Circuit 5 BUILT [95.211.213.148] for GENERAL>
[D]  * <Circuit 6 BUILT [72.84.220.123] for GENERAL>
[D]  * <Circuit 7 BUILT [95.211.213.146] for GENERAL>
[D]  * <Circuit 8 BUILT [37.130.227.132] for GENERAL>
[D]  * <Circuit 9 EXTENDED [] for GENERAL>
[D]  * <Circuit 10 EXTENDED [] for GENERAL>
[D]  * <Circuit 11 BUILT [192.95.14.16] for GENERAL>
[D]  * <Circuit 12 BUILT [96.47.226.20] for GENERAL>
[D]  * <Circuit 13 BUILT [80.237.226.74] for GENERAL>
[D]  * <Circuit 14 BUILT [95.211.213.146] for GENERAL>
[D]  * <Circuit 15 BUILT [93.182.129.86] for GENERAL>
[D]  * <Circuit 16 BUILT [93.182.129.84] for GENERAL>
[D]  * <Circuit 17 BUILT [88.198.219.54] for GENERAL>
[D]  * <Circuit 18 BUILT [67.205.112.74] for GENERAL>
[D]  * <Circuit 19 BUILT [109.163.233.200] for GENERAL>
[D]  * <Circuit 20 BUILT [93.215.73.65] for GENERAL>
[D]  * <Circuit 21 BUILT [109.163.233.202] for GENERAL>
[D]  * <Circuit 22 BUILT [77.247.181.162] for GENERAL>
[D]  * <Circuit 23 EXTENDED [] for GENERAL>
[D]  * <Circuit 24 BUILT [204.11.50.131] for GENERAL>
[D]  * <Circuit 25 BUILT [85.214.60.194 80.237.226.74 166.70.154.130] for GENERAL>
[D]  * <Circuit 26 EXTENDED [78.46.194.132] for GENERAL>
[D]  * <Circuit 27 EXTENDED [] for GENERAL>
[D] Obtained our IP address from a Tor Relay 38.111.11.2
[D] adding callback for startNetTest
[D] Creating ./report-dns_consistency-2013-03-21T075945Z.yamloo
[D] Writing report with YAML reporter
Reporting httpo://nkvphnp3p6agi5qq.onion/report
[D] Sending {"software_name": "ooniprobe", "software_version": "0.0.10", "content": "---\noptions:\n  collector: null\n  help: 0\n  logfile: null\n  no-default
-reporter: 0\n  parallelism: '10'\n  pcapfile: null\n  reportfile: null\n  resume: 0\n  subargs: [-f, private/lists/ping-me.list]\n  test: nettests/blocking/dn
sconsistency.py\n  testdeck: null\nprobe_asn: AS0\nprobe_cc: null\nprobe_ip: 127.0.0.1\nsoftware_name: ooniprobe\nsoftware_version: 0.0.10\nstart_time: 1363852
785.0\ntest_name: dns_consistency\ntest_version: '0.5'\n...\n", "test_version": "0.5", "test_name": "dns_consistency", "probe_asn": "AS0"}
Creating report with OONIB Reporter. Please be patient.
This may take up to 1-2 minutes...
[D] Reporters created: [<Deferred at 0x2992f38 current result: <ooni.reporter.YAMLReporter object at 0x31d3cd0>>, <Deferred at 0x29b10e0>]
[D] Running dnsconsistency default processor
[D] Running <class 'nettests.blocking.dnsconsistency.DNSConsistencyTest'> test_a_lookup
[D] Created report with id 2013-03-21T080006Z_AS0_17aqoi8qbJaSWqR9YcmmrQwp3PQM4zsGjAFhBaETjiwOZgKaYW

comment:2 Changed 6 years ago by hellais

Proper handling of report failures have been added to later versions of ooni-probe. If this bug persists please reopen the ticket.

comment:3 Changed 6 years ago by hellais

Resolution: fixed
Status: newclosed
Note: See TracTickets for help on using tickets.