Opened 16 months ago

Last modified 14 months ago

#7788 new defect

null dereference when bufferevents are on

Reported by: lemerange Owned by:
Priority: major Milestone: Tor: unspecified
Component: Tor Version: Tor: 0.2.3.25
Keywords: crash cpu_worker tor-relay bufferevents Cc: jvoss@…, blueness
Actual Points: Parent ID:
Points:

Description

The relay is shutting down approximately every three days. There are no messages in the syslog.

After first noticing the problem I switched to info logging, and found more information. Not sure it is enough information.

I have reason to believe that this problem began after upgrading to 2.3.25 version, but, again, sorry, cant be sure of that. It had run reliably in this configuration for some time. Other system software may have also been upgraded.

I cannot get a stack trace as I don't reliably know yet exactly when the issue occurs, and as it stands the log file is 3.5 GB--I may run the disk full on debug?

It is not clear if this occurs reliably when keys are rotated. I am running again now in debug log mode, and will update with when exactly the next crash occurs. On this run, this was the first time the keys were rotated.

System Info
Linux kernel 3.4.5 with pax and grsec patch.

libevent 2.0.20
tor version: Tor v0.2.3.25 (git-17c24b3118224d65) (with bufferevents) running on Linux. Compiled from source on
openssl 1.0.0.j compiled with sse2 and zlib support.
4 amd64 cpu's.

System running in chroot environment

ldd tor

linux-vdso.so.1
libz.so.1 => /lib64/libz.so.1
libm.so.6 => /lib64/libm.so.6
libevent-2.0.so.5 => /usr/lib64/libevent-2.0.so.5
libssl.so.1.0.0 => /usr/lib64/libssl.so.1.0.0
libcrypto.so.1.0.0 => /usr/lib64/libcrypto.so.1.0.0
librt.so.1 => /lib64/librt.so.1
libdl.so.2 => /lib64/libdl.so.2
libc.so.6 => /lib64/libc.so.6
libpthread.so.0 => /lib64/libpthread.so.0
/lib64/ld-linux-x86-64.so.2

--- Torrc File ------------------
Log info file /var/log/tor/notices.log
RunAsDaemon 1
DataDirectory /var/lib/tor
ORPort 9001
ORListenAddress <snip>
Nickname <snipped>
Address <snipped>
RelayBandwidthRate 3250 KB # Throttle traffic to 100KB/s (800Kbps)
RelayBandwidthBurst 4500 KB # But allow bursts up to 200KB/s (1600Kbps)

AccountingMax 6000 GB
AccountingStart month 20 00:00

#DirPort 9030 # what port to advertise for directory connections
#DirListenAddress 0.0.0.0:9091
#BridgeRelay 1
#ExitPolicy reject *:*
#ExitPolicy reject *:25,accept *:*

ExitPolicy accept *:20-23 # FTP, SSH, telnet
ExitPolicy accept *:43 # WHOIS
ExitPolicy accept *:53 # DNS
ExitPolicy accept *:79-81 # finger, HTTP
ExitPolicy accept *:88 # kerberos
ExitPolicy accept *:110 # POP3
ExitPolicy accept *:143 # IMAP
ExitPolicy accept *:194 # IRC
ExitPolicy accept *:220 # IMAP3
ExitPolicy accept *:389 # LDAP
ExitPolicy accept *:443 # HTTPS
ExitPolicy accept *:464 # kpasswd
ExitPolicy accept *:465 # smtp
ExitPolicy accept *:531 # IRC/AIM
ExitPolicy accept *:543-544 # Kerberos
ExitPolicy accept *:554 # RTSP
ExitPolicy accept *:563 # NNTP over SSL
ExitPolicy accept *:636 # LDAP over SSL
ExitPolicy accept *:706 # SILC
ExitPolicy accept *:749 # kerberos
ExitPolicy accept *:873 # rsync
ExitPolicy accept *:902-904 # VMware
ExitPolicy accept *:995 # pop
ExitPolicy accept *:981 # Remote HTTPS management for firewall
ExitPolicy accept *:989-995 # FTP over SSL, Netnews Administration System, telnets, IMAP over SSL, ircs, POP3 over SSL
ExitPolicy accept *:1194 # OpenVPN
ExitPolicy accept *:1220 # QT Server Admin
ExitPolicy accept *:1293 # PKT-KRB-IPSec
ExitPolicy accept *:1500 # VLSI License Manager
ExitPolicy accept *:1533 # Sametime
ExitPolicy accept *:1677 # GroupWise
ExitPolicy accept *:1723 # PPTP
ExitPolicy accept *:1755 # RTSP
ExitPolicy accept *:1863 # MSNP
ExitPolicy accept *:2082 # Infowave Mobility Server
ExitPolicy accept *:2083 # Secure Radius Service (radsec)
ExitPolicy accept *:2086-2087 # GNUnet, ELI
ExitPolicy accept *:2095-2096 # NBX
ExitPolicy accept *:2102-2104 # Zephyr
ExitPolicy accept *:3128 # SQUID
ExitPolicy accept *:3389 # MS WBT
ExitPolicy accept *:3690 # SVN
ExitPolicy accept *:4321 # RWHOIS
ExitPolicy accept *:4643 # Virtuozzo
ExitPolicy accept *:5050 # MMCC
ExitPolicy accept *:5190 # ICQ
ExitPolicy accept *:5222-5223 # XMPP, XMPP over SSL
ExitPolicy accept *:5228 # Android Market
ExitPolicy accept *:5900 # VNC
ExitPolicy accept *:6660-6669 # IRC
ExitPolicy accept *:6679 # IRC SSL
ExitPolicy accept *:6697 # IRC SSL
ExitPolicy accept *:8000 # iRDMI
ExitPolicy accept *:8008 # HTTP alternate
ExitPolicy accept *:8074 # Gadu-Gadu
ExitPolicy accept *:8080 # HTTP Proxies
ExitPolicy accept *:8087-8088 # Simplify Media SPP Protocol, Radan HTTP
ExitPolicy accept *:8332-8333 # BitCoin
ExitPolicy accept *:8443 # PCsync HTTPS
ExitPolicy accept *:8888 # HTTP Proxies, NewsEDGE
ExitPolicy accept *:9119 # Chat
ExitPolicy accept *:9418 # git
ExitPolicy accept *:9999 # distinct
ExitPolicy accept *:10000 # Network Data Management Protocol
ExitPolicy accept *:11371 # OpenPGP hkp (http keyserver protocol)
ExitPolicy accept *:19294 # Google Voice TCP
ExitPolicy accept *:19638 # Ensim control panel
ExitPolicy reject *:*


AccountingBytesReadInInterval 257316040704
AccountingBytesWrittenInInterval 261737760768
AccountingExpectedUsage 50954347
AccountingIntervalStart 2012-12-20 00:00:00
AccountingSecondsActive 250617
EntryGuard dawn 88CC8EFEAE71B10328060E72D0AFAC6D11968C30
EntryGuardAddedBy 88CC8EFEAE71B10328060E72D0AFAC6D11968C30 0.2.3.25 2012-11-27 05:40:22
EntryGuardPathBias 40 71
EntryGuard Unnamed 68AAB9223167F71A5FF167B76491E116C3EB7612
EntryGuardAddedBy 68AAB9223167F71A5FF167B76491E116C3EB7612 0.2.3.25 2012-11-08 15:28:37
EntryGuardPathBias 44 69
EntryGuard FcosVmTH A87FB50AE3FD26697F57AC7E9D00470B0B194886
EntryGuardAddedBy A87FB50AE3FD26697F57AC7E9D00470B0B194886 0.2.3.25 2012-11-26 09:46:45
EntryGuardPathBias 26 46
EntryGuard AccessNowKromyon21 1D024F41EDBF3F061E1341D516543090D8A44B42
EntryGuardDownSince 2012-12-22 19:57:14 2012-12-22 19:57:14
EntryGuardUnlistedSince 2012-12-22 21:06:50
EntryGuardAddedBy 1D024F41EDBF3F061E1341D516543090D8A44B42 0.2.3.25 2012-11-30 04:56:13
EntryGuard PPrivCom012 D82183B1C09E1D7795FF2D7116BAB5106AA3E60E
EntryGuardAddedBy D82183B1C09E1D7795FF2D7116BAB5106AA3E60E 0.2.3.25 2012-12-02 15:01:33
BWHistoryReadEnds 2012-12-22 21:42:13
BWHistoryReadValues 949090304,974959616,961193984,834570240,950305792,1041410048,842811392,746615808,747693056,642286592,860041216,756172800,683798528,1030409216,1289200640,934102016,1043067904,1008646144,1140732928,829616128,1235257344,988864512,508288000,604825600,465355776,620781568,772946944,741688320,574982144,442335232,643431424,664923136,465909760,685237248,587547648,590520320,697316352,547024896,560828416,630496256,586646528,516692992,1090369536,1165987840,1144031232,1233311744,1205667840,1251311616,1285562368,1190880256,1156283392,985275392,929112064,934960128,963703808,1172762624,1136047104,1283840000,769631232,815806464,950857728,875366400,911552512,1028167680,844773376,1213130752,1193753600,1221725184,1021349888,951879680,1561461760,940029952,987204608,1143710720,984419328,893962240,865945600,911310848,1195461632,1104334848,1059777536,1158386688,1166144512,1214245888,1068372992,1163715584,1195211776,972351488,905847808,966798336,1259452416,1159996416,1136475136,1053933568,926558208,698471424,779595776
BWHistoryReadMaxima 1529856,1396736,1686528,1574912,1671168,1833984,1619968,1248256,1211392,1142784,1505280,1344512,2045952,1989632,2227200,1753088,1780736,1620992,1859584,1286144,2101248,2060288,1103872,1301504,1654784,1431552,1321984,1221632,1140736,1476608,1188864,1468416,1042432,1553408,1373184,1525760,1783808,1164288,1028096,1324032,1378304,948224,2772992,1899520,2310144,2184192,1912832,1970176,1946624,1934336,2062336,1802240,1782784,1528832,1909760,2177024,1867776,2408448,1473536,1560576,1652736,1497088,1429504,1865728,1572864,2146304,1806336,1917952,1960960,1776640,2331648,1705984,1717248,2000896,1566720,1587200,1352704,1500160,1908736,1817600,1628160,1868800,1859584,1940480,1591296,1659904,1863680,1795072,1681408,1635328,2257920,2032640,1735680,1990656,1668096,1466368,2299904
BWHistoryWriteEnds 2012-12-22 21:42:13
BWHistoryWriteValues 966266880,993686528,979760128,850405376,969452544,1060314112,859262976,760714240,761665536,655068160,875930624,768262144,697755648,1050351616,1321699328,956244992,1071892480,1034382336,1162412032,848030720,1263919104,1017668608,518780928,627184640,473708544,636611584,799344640,758071296,555555840,452220928,656167936,679224320,477203456,702065664,597983232,601352192,713262080,559119360,571159552,643559424,598084608,526529536,1105819648,1187366912,1168007168,1260184576,1227403264,1275583488,1308205056,1214534656,1176144896,999650304,942600192,946432000,980539392,1189735424,1154594816,1301262336,779598848,828180480,969856000,888669184,926757888,1049107456,861310976,1233208320,1217050624,1243755520,1045451776,970458112,1590680576,957883392,1007980544,1164898304,1007049728,911465472,881814528,927215616,1215427584,1125384192,1075299328,1175808000,1184960512,1232360448,1085959168,1183973376,1215822848,988649472,921987072,987149312,1279882240,1177083904,1158433792,1001771008,942543872,714211328,792785920
BWHistoryWriteMaxima 1569792,1419264,1717248,1608704,1694720,1872896,1657856,1278976,1230848,1173504,1532928,1362944,2079744,2036736,2269184,1785856,1837056,1678336,1893376,1317888,2156544,2109440,1132544,1358848,1701888,1488896,1368064,1256448,1176576,1521664,1192960,1495040,1088512,1589248,1401856,1552384,1817600,1183744,1052672,1337344,1395712,969728,2816000,1931264,2344960,2214912,1963008,2006016,1983488,1974272,2083840,1840128,1810432,1546240,1894400,2207744,1903616,2458624,1486848,1593344,1727488,1499136,1439744,1910784,1605632,2198528,1841152,1953792,2002944,1814528,2371584,1740800,1766400,2057216,1615872,1629184,1376256,1518592,1906688,1868800,1665024,1902592,1878016,1951744,1609728,1689600,1913856,1814528,1697792,1681408,2293760,2071552,1773568,1538048,1682432,1484800,2332672
BWHistoryDirReadEnds 2012-12-18 07:56:38
BWHistoryDirReadValues 0
BWHistoryDirReadMaxima 0
BWHistoryDirWriteEnds 2012-12-18 07:56:38
BWHistoryDirWriteValues 0
BWHistoryDirWriteMaxima 0
TorVersion Tor 0.2.3.25 (git-17c24b3118224d65)
LastRotatedOnionKey 2012-12-22 21:37:48
LastWritten 2012-12-22 21:37:48
TotalBuildTimes 411
CircuitBuildAbandonedCount 25
CircuitBuildTimeBin 125 1
CircuitBuildTimeBin 175 1
CircuitBuildTimeBin 225 6
CircuitBuildTimeBin 275 2
CircuitBuildTimeBin 325 1
CircuitBuildTimeBin 375 8
CircuitBuildTimeBin 425 5
CircuitBuildTimeBin 475 7
CircuitBuildTimeBin 525 10
CircuitBuildTimeBin 575 6
CircuitBuildTimeBin 625 9
CircuitBuildTimeBin 675 6
CircuitBuildTimeBin 725 8
CircuitBuildTimeBin 775 10
CircuitBuildTimeBin 825 10
CircuitBuildTimeBin 875 13
CircuitBuildTimeBin 925 6
CircuitBuildTimeBin 975 9
CircuitBuildTimeBin 1025 6
CircuitBuildTimeBin 1075 4
CircuitBuildTimeBin 1125 7
CircuitBuildTimeBin 1175 4
CircuitBuildTimeBin 1225 4
CircuitBuildTimeBin 1275 2
CircuitBuildTimeBin 1325 8
CircuitBuildTimeBin 1375 3
CircuitBuildTimeBin 1425 3
CircuitBuildTimeBin 1475 6
CircuitBuildTimeBin 1525 2
CircuitBuildTimeBin 1575 8
CircuitBuildTimeBin 1625 5
CircuitBuildTimeBin 1675 2
CircuitBuildTimeBin 1725 5
CircuitBuildTimeBin 1775 6
CircuitBuildTimeBin 1825 3
CircuitBuildTimeBin 1875 5
CircuitBuildTimeBin 1925 1
CircuitBuildTimeBin 1975 1
CircuitBuildTimeBin 2025 3
CircuitBuildTimeBin 2075 3
CircuitBuildTimeBin 2125 2
CircuitBuildTimeBin 2175 4
CircuitBuildTimeBin 2225 3
CircuitBuildTimeBin 2275 3
CircuitBuildTimeBin 2325 1
CircuitBuildTimeBin 2375 4
CircuitBuildTimeBin 2425 1
CircuitBuildTimeBin 2525 2
CircuitBuildTimeBin 2575 2
CircuitBuildTimeBin 2625 3
CircuitBuildTimeBin 2675 1
CircuitBuildTimeBin 2725 2
CircuitBuildTimeBin 2775 2
CircuitBuildTimeBin 2825 1
CircuitBuildTimeBin 2875 2
CircuitBuildTimeBin 2925 2
CircuitBuildTimeBin 2975 3
CircuitBuildTimeBin 3025 3
CircuitBuildTimeBin 3075 1
CircuitBuildTimeBin 3125 3
CircuitBuildTimeBin 3175 1
CircuitBuildTimeBin 3275 3
CircuitBuildTimeBin 3325 1
CircuitBuildTimeBin 3375 1
CircuitBuildTimeBin 3575 3
CircuitBuildTimeBin 3625 2
CircuitBuildTimeBin 3675 2
CircuitBuildTimeBin 3775 1
CircuitBuildTimeBin 3825 1
CircuitBuildTimeBin 3875 1
CircuitBuildTimeBin 3925 1
CircuitBuildTimeBin 3975 3
CircuitBuildTimeBin 4025 2
CircuitBuildTimeBin 4075 1
CircuitBuildTimeBin 4125 1
CircuitBuildTimeBin 4225 1
CircuitBuildTimeBin 4275 2
CircuitBuildTimeBin 4325 1
CircuitBuildTimeBin 4425 1
CircuitBuildTimeBin 4475 3
CircuitBuildTimeBin 4525 2
CircuitBuildTimeBin 4575 2
CircuitBuildTimeBin 4625 2
CircuitBuildTimeBin 4725 2
CircuitBuildTimeBin 4775 4
CircuitBuildTimeBin 4825 3
CircuitBuildTimeBin 4875 1
CircuitBuildTimeBin 5025 2
CircuitBuildTimeBin 5075 2
CircuitBuildTimeBin 5175 1
CircuitBuildTimeBin 5225 2
CircuitBuildTimeBin 5275 2
CircuitBuildTimeBin 5325 2
CircuitBuildTimeBin 5425 1
CircuitBuildTimeBin 5675 1
CircuitBuildTimeBin 5725 1
CircuitBuildTimeBin 5775 1
CircuitBuildTimeBin 5825 1
CircuitBuildTimeBin 5875 1
CircuitBuildTimeBin 5975 3
CircuitBuildTimeBin 6275 1
CircuitBuildTimeBin 6325 1
CircuitBuildTimeBin 6375 2
CircuitBuildTimeBin 6575 1
CircuitBuildTimeBin 6775 1
CircuitBuildTimeBin 6825 1
CircuitBuildTimeBin 6875 1
CircuitBuildTimeBin 6925 2
CircuitBuildTimeBin 7025 1
CircuitBuildTimeBin 7075 1
CircuitBuildTimeBin 7125 1
CircuitBuildTimeBin 7175 1
CircuitBuildTimeBin 7225 1
CircuitBuildTimeBin 7875 1
CircuitBuildTimeBin 8025 1
CircuitBuildTimeBin 8125 2
CircuitBuildTimeBin 8225 1
CircuitBuildTimeBin 8475 1
CircuitBuildTimeBin 8525 1
CircuitBuildTimeBin 8625 2
CircuitBuildTimeBin 8675 1
CircuitBuildTimeBin 8725 1
CircuitBuildTimeBin 8825 1
CircuitBuildTimeBin 8975 2
CircuitBuildTimeBin 9125 1
CircuitBuildTimeBin 9175 1
CircuitBuildTimeBin 9475 1
CircuitBuildTimeBin 9575 1
CircuitBuildTimeBin 9925 1
CircuitBuildTimeBin 10525 1
CircuitBuildTimeBin 10575 1
CircuitBuildTimeBin 10625 1
CircuitBuildTimeBin 10775 1
CircuitBuildTimeBin 10925 1
CircuitBuildTimeBin 11125 1
CircuitBuildTimeBin 11175 1
CircuitBuildTimeBin 11375 2
CircuitBuildTimeBin 11875 1
CircuitBuildTimeBin 11925 1
CircuitBuildTimeBin 12525 1
CircuitBuildTimeBin 12625 1
CircuitBuildTimeBin 12975 1
CircuitBuildTimeBin 13225 1
CircuitBuildTimeBin 13725 1
CircuitBuildTimeBin 14075 1
CircuitBuildTimeBin 14825 1
CircuitBuildTimeBin 14875 1
CircuitBuildTimeBin 16375 1
CircuitBuildTimeBin 16925 1
CircuitBuildTimeBin 17175 1
CircuitBuildTimeBin 17325 1
CircuitBuildTimeBin 18225 1
CircuitBuildTimeBin 20525 1
CircuitBuildTimeBin 21575 1
CircuitBuildTimeBin 25825 1
CircuitBuildTimeBin 28225 1
CircuitBuildTimeBin 31975 1
CircuitBuildTimeBin 54775 1


Dec 22 21:37:36.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:36.000 [info] connection_edge_process_relay_cell(): 304: end cell (misc error) for stream 55385. Removing stream.
Dec 22 21:37:36.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:36.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:36.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:36.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:36.000 [info] connection_edge_reached_eof(): conn (fd 158) reached eof. Closing.
Dec 22 21:37:36.000 [info] connection_edge_process_relay_cell(): 283: end cell (misc error) for stream 40709. Removing stream.
Dec 22 21:37:37.000 [info] connection_edge_reached_eof(): conn (fd 180) reached eof. Closing.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 28728).
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:37.000 [info] eventdns: Resolve requested.
Dec 22 21:37:37.000 [info] eventdns: Setting timeout for request 0x4b83fa16d0, sent to nameserver 0x4b8251d840
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_reached_eof(): conn (fd 17) reached eof. Closing.
Dec 22 21:37:37.000 [info] eventdns: Removing timeout for request 0x4b83fa16d0
Dec 22 21:37:37.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:37.000 [info] eventdns: Resolve requested.
Dec 22 21:37:37.000 [info] eventdns: Setting timeout for request 0x4b82bdc3a0, sent to nameserver 0x4b8251da50
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:38225; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): 154: end cell (misc error) for stream 21082. Removing stream.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] eventdns: Removing timeout for request 0x4b82bdc3a0
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:38225: Waiting for AUTHENTICATE.
Dec 22 21:37:37.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:9001: Looks good.
Dec 22 21:37:37.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:9001; OR connection is now open, using protocol version 3. Its ID digest is 87970FFE50E1588412313E2E724F7BB206FC7D16
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): 202: end cell (misc error) for stream 55390. Removing stream.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): 172: end cell (misc error) for stream 55389. Removing stream.
Dec 22 21:37:37.000 [info] connection_edge_reached_eof(): conn (fd 672) reached eof. Closing.
Dec 22 21:37:37.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:37.000 [info] eventdns: Resolve requested.
Dec 22 21:37:37.000 [info] eventdns: Setting timeout for request 0x4b833a04c0, sent to nameserver 0x4b8251d840
Dec 22 21:37:37.000 [info] eventdns: Removing timeout for request 0x4b833a04c0
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:37.000 [info] connection_edge_reached_eof(): conn (fd 309) reached eof. Closing.
Dec 22 21:37:37.000 [info] connection_edge_process_relay_cell(): 280: end cell (misc error) for stream 17861. Removing stream.
Dec 22 21:37:37.000 [info] connection_edge_reached_eof(): conn (fd 137) reached eof. Closing.
Dec 22 21:37:37.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:37.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 27: end cell (misc error) for stream 40717. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_reached_eof(): conn (fd 150) reached eof. Closing.
Dec 22 21:37:38.000 [info] connection_edge_reached_eof(): conn (fd 85) reached eof. Closing.
Dec 22 21:37:38.000 [info] connection_edge_reached_eof(): conn (fd 141) reached eof. Closing.
Dec 22 21:37:38.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:38.000 [info] eventdns: Resolve requested.
Dec 22 21:37:38.000 [info] eventdns: Setting timeout for request 0x4b82f53ce0, sent to nameserver 0x4b8251da50
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] eventdns: Removing timeout for request 0x4b82f53ce0
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 31955).
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 333: end cell (misc error) for stream 55392. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 14: end cell (misc error) for stream 55342. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 232: end cell (misc error) for stream 55381. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 357: end cell (misc error) for stream 55382. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_reached_eof(): conn (fd 304) reached eof. Closing.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:38.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:38.000 [info] connection_edge_process_relay_cell(): 191: end cell (misc error) for stream 41659. Removing stream.
Dec 22 21:37:38.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 222: end cell (misc error) for stream 6866. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 158) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:18803; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:39.000 [info] eventdns: Resolve requested.
Dec 22 21:37:39.000 [info] eventdns: Setting timeout for request 0x4b830407c0, sent to nameserver 0x4b8251d840
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 55: end cell (misc error) for stream 6864. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 593) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 592) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 489) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 380) reached eof. Closing.
Dec 22 21:37:39.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:18803: Waiting for AUTHENTICATE.
Dec 22 21:37:39.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good.
Dec 22 21:37:39.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 3. Its ID digest is BCA53F6BB5C271651B017F2071300CC10CD6E138
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 136: end cell (misc error) for stream 6865. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 246: end cell (misc error) for stream 6863. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 334) reached eof. Closing.
Dec 22 21:37:39.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:39.000 [info] eventdns: Resolve requested.
Dec 22 21:37:39.000 [info] eventdns: Setting timeout for request 0x4b83c42e80, sent to nameserver 0x4b8251da50
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 317) reached eof. Closing.
Dec 22 21:37:39.000 [info] eventdns: Removing timeout for request 0x4b83c42e80
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 583: end cell (misc error) for stream 55363. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 8027).
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 139) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:39.000 [info] eventdns: Removing timeout for request 0x4b830407c0
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 293) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 249: end cell (misc error) for stream 1191. Removing stream.
Dec 22 21:37:39.000 [info] connection_edge_reached_eof(): conn (fd 180) reached eof. Closing.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:39.000 [info] connection_edge_process_relay_cell(): 224: end cell (misc error) for stream 26165. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 171) reached eof. Closing.
Dec 22 21:37:40.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:40.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 27) reached eof. Closing.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): 38: end cell (misc error) for stream 21515. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): 301: end cell (misc error) for stream 29889. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): 294: end cell (misc error) for stream 41672. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): 324: end cell (misc error) for stream 24339. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 86) reached eof. Closing.
Dec 22 21:37:40.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:40.000 [info] eventdns: Resolve requested.
Dec 22 21:37:40.000 [info] eventdns: Setting timeout for request 0x4b8308e110, sent to nameserver 0x4b8251d840
Dec 22 21:37:40.000 [info] eventdns: Removing timeout for request 0x4b8308e110
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): 201: end cell (misc error) for stream 53926. Removing stream.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 136) reached eof. Closing.
Dec 22 21:37:40.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 22817).
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 158) reached eof. Closing.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:40.000 [info] eventdns: Resolve requested.
Dec 22 21:37:40.000 [info] eventdns: Setting timeout for request 0x4b8467f2c0, sent to nameserver 0x4b8251da50
Dec 22 21:37:40.000 [info] eventdns: Removing timeout for request 0x4b8467f2c0
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:40.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:40.000 [info] connection_edge_reached_eof(): conn (fd 191) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): 133: end cell (misc error) for stream 52749. Removing stream.
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 32) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): 203: end cell (misc error) for stream 29890. Removing stream.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): 254: end cell (misc error) for stream 42251. Removing stream.
Dec 22 21:37:41.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:41.000 [info] eventdns: Resolve requested.
Dec 22 21:37:41.000 [info] eventdns: Setting timeout for request 0x4b84359430, sent to nameserver 0x4b8251d840
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 172) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 280) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): 21: end cell (misc error) for stream 29891. Removing stream.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 516) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 40643).
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): 295: end cell (misc error) for stream 19531. Removing stream.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 22818).
Dec 22 21:37:41.000 [info] eventdns: Removing timeout for request 0x4b84359430
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 8048).
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 17) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 55393).
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 45) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:41.000 [info] connection_edge_reached_eof(): conn (fd 27) reached eof. Closing.
Dec 22 21:37:41.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 22819).
Dec 22 21:37:41.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 55) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 136) reached eof. Closing.
Dec 22 21:37:42.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:56311; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:42.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:56311: Waiting for AUTHENTICATE.
Dec 22 21:37:42.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good.
Dec 22 21:37:42.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 3. Its ID digest is 6909888BC079756AA1887BA9F827200121A2C5DE
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): 279: end cell (misc error) for stream 7890. Removing stream.
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 280) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 171) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 201) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 384) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 394) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 8032).
Dec 22 21:37:42.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:42.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:42.000 [info] eventdns: Resolve requested.
Dec 22 21:37:42.000 [info] eventdns: Setting timeout for request 0x4b84dd9b40, sent to nameserver 0x4b8251da50
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 249) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): 35: end cell (misc error) for stream 49158. Removing stream.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): 229: end cell (misc error) for stream 40721. Removing stream.
Dec 22 21:37:42.000 [info] connection_edge_process_relay_cell(): 325: end cell (misc error) for stream 60056. Removing stream.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 694) reached eof. Closing.
Dec 22 21:37:42.000 [info] connection_edge_reached_eof(): conn (fd 133) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 254) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:43.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): 343: end cell (misc error) for stream 62630. Removing stream.
Dec 22 21:37:43.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 314) reached eof. Closing.
Dec 22 21:37:43.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:41425; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:43.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:43.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:43.000 [info] eventdns: Resolve requested.
Dec 22 21:37:43.000 [info] eventdns: Setting timeout for request 0x4b83b498e0, sent to nameserver 0x4b8251d840
Dec 22 21:37:43.000 [info] eventdns: Removing timeout for request 0x4b83b498e0
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): 86: end cell (misc error) for stream 29894. Removing stream.
Dec 22 21:37:43.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:43.000 [info] eventdns: Resolve requested.
Dec 22 21:37:43.000 [info] eventdns: Setting timeout for request 0x4b833aa090, sent to nameserver 0x4b8251da50
Dec 22 21:37:43.000 [info] eventdns: Removing timeout for request 0x4b833aa090
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] eventdns: Removing timeout for request 0x4b84dd9b40
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:41425: Waiting for AUTHENTICATE.
Dec 22 21:37:43.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good.
Dec 22 21:37:43.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 3. Its ID digest is D9668BC3F96FF4BBFFEF9F8BA69E92666DE7A595
Dec 22 21:37:43.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:43.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:43.000 [info] eventdns: Resolve requested.
Dec 22 21:37:43.000 [info] eventdns: Setting timeout for request 0x4b83014110, sent to nameserver 0x4b8251d840
Dec 22 21:37:43.000 [info] eventdns: Removing timeout for request 0x4b83014110
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 45) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 27) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 599) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_reached_eof(): conn (fd 481) reached eof. Closing.
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 22820).
Dec 22 21:37:43.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 8031).
Dec 22 21:37:43.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 265 (140.186.70.48:443) [idle 606].
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:43.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_tls_continue_handshake(): Client got a v3 cert! Moving on to v3 handshake.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_process_relay_cell(): sendme cell dropped, unknown stream (streamid 40643).
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:9001; Sending cells: CERTS
Dec 22 21:37:44.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:9001: Authenticated it.
Dec 22 21:37:44.000 [info] command_process_auth_challenge_cell(): Got an AUTH_CHALLENGE cell from [scrubbed]:9001: Sending authentication
Dec 22 21:37:44.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:9001; OR connection is now open, using protocol version 3. Its ID digest is 9208E806C49D7363B288C3A36F05E7A17B7031D4
Dec 22 21:37:44.000 [info] connection_edge_process_relay_cell(): 32: end cell (misc error) for stream 29895. Removing stream.
Dec 22 21:37:44.000 [info] connection_edge_reached_eof(): conn (fd 236) reached eof. Closing.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:44.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:44.000 [info] connection_edge_reached_eof(): conn (fd 17) reached eof. Closing.
Dec 22 21:37:44.000 [info] connection_edge_reached_eof(): conn (fd 333) reached eof. Closing.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:44.000 [info] connection_edge_process_relay_cell(): 309: end cell (misc error) for stream 13547. Removing stream.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:44.000 [info] connection_edge_reached_eof(): conn (fd 343) reached eof. Closing.
Dec 22 21:37:44.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_process_relay_cell(): 336: end cell (misc error) for stream 6867. Removing stream.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_process_relay_cell(): 122: end cell (misc error) for stream 11896. Removing stream.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_reached_eof(): conn (fd 385) reached eof. Closing.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_reached_eof(): conn (fd 408) reached eof. Closing.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:43056; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:45.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:43056: Waiting for AUTHENTICATE.
Dec 22 21:37:45.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good.
Dec 22 21:37:45.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 3. Its ID digest is 5FB9FAFE62F4F6037E555FEE160C260ED4DFD481
Dec 22 21:37:45.000 [info] connection_edge_process_relay_cell(): 45: end cell (misc error) for stream 46788. Removing stream.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:45.000 [info] connection_edge_reached_eof(): conn (fd 358) reached eof. Closing.
Dec 22 21:37:45.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:45908; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:45908: Waiting for AUTHENTICATE.
Dec 22 21:37:45.000 [info] command_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good.
Dec 22 21:37:45.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 3. Its ID digest is 1A7837886537D87C2CD4426EB990A60B57559C03
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:45.000 [info] connection_edge_process_relay_cell(): 14: end cell (misc error) for stream 40711. Removing stream.
Dec 22 21:37:45.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 203: end cell (misc error) for stream 42252. Removing stream.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 28732).
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 132: end cell (misc error) for stream 15801. Removing stream.
Dec 22 21:37:46.000 [info] connection_edge_reached_eof(): conn (fd 152) reached eof. Closing.
Dec 22 21:37:46.000 [info] connection_edge_reached_eof(): conn (fd 1026) reached eof. Closing.
Dec 22 21:37:46.000 [info] connection_edge_reached_eof(): conn (fd 87) reached eof. Closing.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 172: end cell (misc error) for stream 29896. Removing stream.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:46.000 [info] eventdns: Resolve requested.
Dec 22 21:37:46.000 [info] eventdns: Setting timeout for request 0x4b84fb4860, sent to nameserver 0x4b8251da50
Dec 22 21:37:46.000 [info] eventdns: Removing timeout for request 0x4b84fb4860
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 98: end cell (misc error) for stream 51487. Removing stream.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 133: end cell (misc error) for stream 21084. Removing stream.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_reached_eof(): conn (fd 65) reached eof. Closing.
Dec 22 21:37:46.000 [info] connection_edge_process_relay_cell(): 224: end cell (misc error) for stream 29810. Removing stream.
Dec 22 21:37:46.000 [info] connection_tls_continue_handshake(): Client got a v3 cert! Moving on to v3 handshake.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:46.000 [info] connection_edge_reached_eof(): conn (fd 172) reached eof. Closing.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:46.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:443 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] command_process_versions_cell(): Negotiated version 3 with [scrubbed]:9001; Sending cells: CERTS
Dec 22 21:37:47.000 [info] command_process_certs_cell(): Got some good certificates from [scrubbed]:9001: Authenticated it.
Dec 22 21:37:47.000 [info] command_process_auth_challenge_cell(): Got an AUTH_CHALLENGE cell from [scrubbed]:9001: Sending authentication
Dec 22 21:37:47.000 [info] command_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:9001; OR connection is now open, using protocol version 3. Its ID digest is BF39ACDFF9E5ADAA71432C4394A6883576C8F3DA
Dec 22 21:37:47.000 [info] connection_edge_reached_eof(): conn (fd 343) reached eof. Closing.
Dec 22 21:37:47.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:47.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:47.000 [info] launch_resolve(): Launching eventdns request for [scrubbed]
Dec 22 21:37:47.000 [info] eventdns: Resolve requested.
Dec 22 21:37:47.000 [info] eventdns: Setting timeout for request 0x4b83b41f90, sent to nameserver 0x4b8251d840
Dec 22 21:37:47.000 [info] connection_edge_process_relay_cell(): 144: end cell (misc error) for stream 6588. Removing stream.
Dec 22 21:37:47.000 [info] eventdns: Removing timeout for request 0x4b83b41f90
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:47.000 [info] connection_edge_reached_eof(): conn (fd 14) reached eof. Closing.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 1181 (188.142.102.77:9001) [idle 180].
Dec 22 21:37:47.000 [info] connection_edge_reached_eof(): conn (fd 375) reached eof. Closing.
Dec 22 21:37:47.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:47.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 689) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): 32: end cell (misc error) for stream 29899. Removing stream.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 477) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): end cell (misc error) dropped, unknown stream.
Dec 22 21:37:48.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 381) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): 325: end cell (misc error) for stream 29897. Removing stream.
Dec 22 21:37:48.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 152) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 304) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 425) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 334) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 28732).
Dec 22 21:37:48.000 [info] run_scheduled_events(): Rotating onion key.
Dec 22 21:37:48.000 [info] rotate_onion_key(): Rotating onion key
Dec 22 21:37:48.000 [info] mark_my_descriptor_dirty(): Decided to publish new relay descriptor: rotated onion key
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] router_rebuild_descriptor(): Rebuilding relay descriptor (forced)
Dec 22 21:37:48.000 [info] extrainfo_dump_to_string(): Adding stats to extra-info descriptor.
Dec 22 21:37:48.000 [info] router_upload_dir_desc_to_dirservers(): Uploading relay descriptor to directory authorities

Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] directory_post_to_dirservers(): Uploading an extrainfo too (length 2954)
Dec 22 21:37:48.000 [info] router_pick_published_address(): Success: chose address '95.170.88.81'.
Dec 22 21:37:48.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 590 (194.109.206.212:443) [idle 180].
Dec 22 21:37:48.000 [info] cpuworker_main(): CPU worker exiting because Tor process closed connection (either rotated keys or died).
Dec 22 21:37:48.000 [info] or_state_save(): Saved state to "/var/lib/tor/state"
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): 171: end cell (misc error) for stream 15781. Removing stream.
Dec 22 21:37:48.000 [info] connection_edge_reached_eof(): conn (fd 424) reached eof. Closing.
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 28732).
Dec 22 21:37:48.000 [info] connection_edge_process_relay_cell(): data cell dropped, unknown stream (streamid 28732).
Dec 22 21:37:48.000 [info] connection_edge_finished_connecting(): Exit connection to [scrubbed]:80 ([scrubbed]) established.
Dec 22 21:37:48.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:48.000 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished.
Dec 22 21:37:48.000 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished.
Dec 22 21:37:48.000 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished.
Dec 22 21:37:48.000 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished.
Dec 22 21:37:49.000 [info] connection_edge_package_raw_inbuf(): called with package_window 0. Skipping.
Dec 22 21:37:49.000 [info] connection_edge_reached_eof(): conn (fd 343) reached eof. Closing.

Child Tickets

Change History (12)

comment:1 follow-ups: Changed 16 months ago by nickm

  • Keywords tor-relay bufferevents added
  • Milestone set to Tor: unspecified

Does this also occur when running without bufferevents? I'd like to diagnose and fix if we can, but in practice the bufferevent backend is _still_ pretty unstable, and we haven't had the time yet to chase down all of its bugs.

comment:2 in reply to: ↑ 1 Changed 16 months ago by lemerange

Replying to nickm:

Does this also occur when running without bufferevents? I'd like to diagnose and fix if we can, but in practice the bufferevent backend is _still_ pretty unstable, and we haven't had the time yet to chase down all of its bugs.

Sorry for the slow reply. I do not know if bufferevents is running? How do I determine that? I compiled from the source using ./configure --prefix, i didn't change any other settings other then the torrc file above.

UPDATE: It crashed again, this time even less information. I run the disk full with log set on debug, since it has to run for about three days before the problem occurs, and the log file gets too big even after a day or so--I will run the relay once more on info log level.

comment:3 in reply to: ↑ 1 ; follow-up: Changed 16 months ago by lemerange

Replying to nickm:

Does this also occur when running without bufferevents?

Actually, I guess my question is how to run it/compile without bufferevents so I can do your test.

comment:4 in reply to: ↑ 3 Changed 16 months ago by nickm

Replying to lemerange:

Replying to nickm:

Does this also occur when running without bufferevents?

Actually, I guess my question is how to run it/compile without bufferevents so I can do your test.

Re-run the configure script, and when you do, don't pass the --enable-bufferevents optoin

comment:5 Changed 16 months ago by lemerange

  • Status changed from new to needs_information

I suggest you closes this. I have no further information, and I can't determine if this is tor's fault or a problem on my system. I ran the configure script normally--buffer-events seemed to be the default.

comment:6 follow-up: Changed 14 months ago by Javantea

  • Cc jvoss@… added
  • Status changed from needs_information to new

The crash is a null dereference.

The crash occurs in buffers.c:522 in buf_datalen:
return buf->datalen;

In connection.c, conn->outbuf is null.
old_datalen = buf_datalen(conn->outbuf);

This runs because conn->bufev is null which causes IF_HAS_BUFFEREVENT(conn, { ... }); to not run.

Here is a stack trace for you.

Core was generated by `/usr/local/bin/tor -f /etc/tor/torrc'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f2a40265be4 in buf_datalen (buf=0x0) at buffers.c:522
522     {
(gdb) bt
#0  0x00007f2a40265be4 in buf_datalen (buf=0x0) at buffers.c:522
#1  0x00007f2a4029d7b9 in _connection_write_to_buf_impl (
    string=0x7fff8356926e "GET /?sdkjfgaslkgflaksgfia HTTP/1.1\r\nUser-Agent: Opera/9.80 (Windows NT 5.1) Presto/2.12.388 Version/12.12\r\nHost: onlinea.ru\r\nAccept: text/html, application/xml;q=0.9, application/xhtml+xml, image/png"..., len=411,
    conn=0x7f2a4315eab0, zlib=0) at connection.c:3412
#2  0x00007f2a40227eac in connection_write_to_buf (conn=0x7f2a4315eab0, len=<optimized out>,
    string=0x7fff8356926e "GET /?sdkjfgaslkgflaksgfia HTTP/1.1\r\nUser-Agent: Opera/9.80 (Windows NT 5.1) Presto/2.12.388 Version/12.12\r\nHost: onlinea.ru\r\nAccept: text/html, application/xml;q=0.9, application/xhtml+xml, image/png"...) at connection.h:104
#3  connection_edge_process_relay_cell (cell=0x7fff83569260, circ=0x7f2a428f1e30, conn=0x7f2a4315eab0, layer_hint=<optimized out>)
    at relay.c:1134
#4  0x00007f2a4022973d in circuit_receive_relay_cell (cell=0x7fff83569260, circ=0x7f2a428f1e30, cell_direction=CELL_DIRECTION_OUT)
    at relay.c:192
#5  0x00007f2a402824ae in command_process_relay_cell (conn=0x7f2a423c5e90, cell=0x7fff83569260) at command.c:576
#6  command_process_cell (cell=0x7fff83569260, conn=0x7f2a423c5e90) at command.c:192
#7  0x00007f2a402aa00f in connection_or_process_cells_from_inbuf (conn=0x7f2a423c5e90) at connection_or.c:1882
#8  0x00007f2a4029b2e5 in connection_handle_read_cb (bufev=<optimized out>, arg=0x7f2a423c5e90) at connection.c:2969
#9  0x00007f2a3f69541e in ?? () from /usr/lib64/libevent-2.0.so.5
#10 0x00007f2a3f68b99b in event_base_loop () from /usr/lib64/libevent-2.0.so.5
#11 0x00007f2a4020ea29 in do_main_loop () at main.c:1959
#12 0x00007f2a4021020b in tor_main (argc=<optimized out>, argv=0x7fff83569968) at main.c:2652
#13 0x00007f2a3e8cf4bd in __libc_start_main () from /lib64/libc.so.6
#14 0x00007f2a4020a1c9 in _start ()

FYI, bufferevents is default on Gentoo, so we should definitely contact them and tell them that it is unstable. You should also check whether other distros enable bufferevents.

I have a patch, if you want it, which fixes this null dereference and an abort that occurs as well. There are several places where similar code occurs, so this probably requires a larger effort. I am testing the patch I wrote right now.

comment:7 Changed 14 months ago by arma

  • Cc blueness added
  • Summary changed from Tor Relay is shutting down every couple of days to null dereference when bufferevents are on

Good stuff!

I agree that somebody should tell Gentoo, if they are indeed turning bufferevents on by default. I'm cc'ing blueness here, who is or was our gentoo maintainer.

comment:8 in reply to: ↑ 6 Changed 14 months ago by cypherpunks

Replying to Javantea:

The crash is a null dereference.

The crash occurs in buffers.c:522 in buf_datalen:
return buf->datalen;

In connection.c, conn->outbuf is null.
old_datalen = buf_datalen(conn->outbuf);

This runs because conn->bufev is null which causes IF_HAS_BUFFEREVENT(conn, { ... }); to not run.

[snip]

FYI, bufferevents is default on Gentoo, so we should definitely contact them and tell them that it is unstable. You should also check whether other distros enable bufferevents.

I have a patch, if you want it, which fixes this null dereference and an abort that occurs as well. There are several places where similar code occurs, so this probably requires a larger effort. I am testing the patch I wrote right now.

While we are contacting Gentoo, they also need to change the tor init script to increase the nofile rlimit setting to 8096(or whatever) in the init script. Gentoo defaults to 0 core size and 1024 fd's.

Thansk for finding this one, between grsec and ulimit issues it took me too long to figure out why it wasn't dropping a core. I have recompiled without bufferevents (also figured out how to change the ulimit by using the prlimit command, which I build into my own init script.)

After starting tor, as root:

TORPID=ps -u toruser --noheaders -o pid
prlimit --nofile=8196:32500 --core=8000000:16000000 --pid $TORPID

I will report back also to verify in a couple of days if the relay crashes again without buffer events, and then we can be more sure its the same bug.

comment:9 Changed 14 months ago by blueness

Okay bufferevents is now off by default. However, our init scripts have ulimit -n 30000. openrc has two pieces to it, the init files are in /etc/init.d and the config files are in /etc/conf.d. In the later, we are setting rc_ulimit="-n 30000".

comment:10 follow-up: Changed 14 months ago by cypherpunks

OK....I made the changes above a few days ago (compile w/o bufferevents and set proper rlimit settings). The relay appears to be running fine. I am also now running the 3.7 kernel.

blueness: OK...I didn't realize that. If you read way above you can see that this relay is running in a chroot jail with a non-standard gentoo. I have had no problems with the standard gentoo...but before I had compiled just using ./configure and it seems THAT defaults to bufferevents enabled, unless I was mistaken. the --disable-bufferevents seemed to kill it.

So as far as now, the relay seems to be working fine, so I think it is safe to assume that my problem was the null dereference problem found in the stack trace.

thanks

comment:11 in reply to: ↑ 10 Changed 14 months ago by cypherpunks

So as far as now, the relay seems to be working fine, so I think it is safe to assume that my problem was the null dereference problem found in the stack trace.

thanks

Mar 06 06:18:37.838 [notice] Tor v0.2.3.25 (git-17c24b3118224d65) running on Linux.

Apologies...latest log from my relay:
Mar 05 12:03:09.000 [notice] Heartbeat: Tor's uptime is 5 days 17:57 hours, with 1438 circuits open. I've sent 645.32 GB and received 637.02 GB.

The relay died again.
Nothing in syslog, nothing in kern.log, and that was the last entry in the tor log. And even though I have the prlimit "core" set, it is still not creating a core file for me.

Not sure what else to do.

comment:12 Changed 14 months ago by cypherpunks

what do I have to do in gentoo linux to have it create a core file? In what conditions would it shutdown without creating a core file?

Note: See TracTickets for help on using tickets.