Opened 12 years ago

Last modified 7 years ago

#672 closed defect (Fixed)

[warn] Still had some address policies cached at shutdown.

Reported by: arma Owned by: nickm
Priority: Low Milestone: 0.2.0.x-final
Component: Core Tor/Tor Version: 0.2.0.24-rc
Severity: Keywords:
Cc: arma, nickm Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Apr 23 14:40:08.135 [notice] Clean shutdown finished. Exiting.
Apr 23 14:40:08.765 [warn] Still had some address policies cached at shutdown.

This happens consistently on moria1 (running 0.2.0.24-rc) and moria2 (running
0.2.1.0-alpha-dev (r14424)).

[Automatically added by flyspray2trac: Operating System: All]

Child Tickets

Change History (12)

comment:1 Changed 11 years ago by arma

This just happened on my Tor client running v0.2.1.11-alpha-dev (r18374).

I ^c'ed it and it ended with

Feb 02 23:22:19.360 [notice] Interrupt: exiting cleanly.
Feb 02 23:22:19.776 [warn] Still had some address policies cached at shutdown.

I also heard a rumor that this still happens sometimes with 0.2.0.33, but I
have not confirmed that yet.

comment:2 Changed 11 years ago by nickm

Hm. I wish I knew which policies these were. If it's not happening all the time, they are unlikely to be
policies in descriptors. Did your client have any policy-like things in its torrc? If not that, then it's
time to go looking through the code to see what we might have missed.

comment:3 Changed 11 years ago by Sebastian

I had this just happen to me on tor-0.2.1.13-alpha that Roger handed out to test. I ran Tor without a config

and a nonexistent ~/.tor directory, so I think it should have been a clean run. Additional tries did not show the message again.

comment:4 Changed 11 years ago by Sebastian

not sure if it's important, but I just remembered that it took my client

a few minutes to progress from 5% to 10% when bootstrapping. Maybe

this triggers the bug?

comment:5 Changed 11 years ago by nickm

It seems that using a nice stale datadir can sometimes trigger this bug. I've added some code in r18827 to try
to diagnose what exactly is going wrong.

comment:6 Changed 11 years ago by nickm

[Looking at the code, I also don't see how we can be leaking policies in this case unless we're also leaking whole
descriptors somehow. Valgrind or dmalloc could be helpful.]

comment:7 Changed 11 years ago by nickm

Quoth Tor:

Mar 16 13:29:37.903 [notice] Tor v0.2.1.13-alpha (r18818). This is experimental software. Do not rely on it for strong anonymity. (Running on Linux i686)
Mar 16 13:29:56.090 [warn] Still had 924 address policies cached at shutdown.
Mar 16 13:29:56.090 [warn] 1 [1]: reject 173.49.70.164:*
Mar 16 13:29:56.091 [warn] 2 [1]: accept *:80-82
Mar 16 13:29:56.091 [warn] 3 [387]: reject 169.254.0.0/16:*
Mar 16 13:29:56.091 [warn] 4 [31]: accept *:5190
Mar 16 13:29:56.091 [warn] 5 [1]: reject 70.104.132.195:*
Mar 16 13:29:56.091 [warn] 6 [1]: accept 64.27.20.121:80
Mar 16 13:29:56.091 [warn] 7 [1]: reject 216.139.240.0:*
Mar 16 13:29:56.091 [warn] 8 [1]: accept 64.27.20.122:80
Mar 16 13:29:56.091 [warn] 9 [1]: reject 86.204.75.22:*
Mar 16 13:29:56.091 [warn] 10 [1]: reject 140.113.252.45:*

Also sprach dmalloc:

1237224596: 483228: 474012 4310 bn_lib.c:336
1237224596: 483228: 275091 168 routerparse.c:1214
1237224596: 483228: 129240 718 routerparse.c:1205
1237224596: 483228: 126368 1436 rsa_lib.c:132
1237224596: 483228: 57480 2874 bn_lib.c:302
1237224596: 483228: 51696 718 bn_mont.c:350
1237224596: 483228: 41503 718 routerparse.c:1340
1237224596: 483228: 39936 289 container.c:70
1237224596: 483228: 32192 503 container.c:37
1237224596: 483228: 29568 924 policies.c:545
1237224596: 483228: 16801 442 routerparse.c:1344
1237224596: 483228: 12276 1 ra=0x7d725a
1237224596: 483228: 11488 1436 crypto.c:245
1237224596: 483228: 11088 924 policies.c:544
1237224596: 483228: 10037 718 routerparse.c:1238
1237224596: 483228: 9504 792 container.c:34
1237224596: 483228: 8184 1 ra=0x7d7278
1237224596: 483228: 7375 209 routerparse.c:1377
1237224596: 483228: 6999 718 routerparse.c:1233
1237224596: 483228: 1224 1 ra=0x4a209b8
1237224596: 483228: 1024 1 ra=0x4a0a5a4
1237224596: 483228: 573 15 ra=0x4a8b868
1237224596: 483228: 416 1 ra=0x7cb8f8
1237224596: 483228: 398 18 buffer.c:177
1237224596: 483228: 322 6 ra=0x4a8b845
1237224596: 483228: 79 5 ra=0x4a1f39e
1237224596: 483228: 25 2 ra=0x4a0a480
1237224596: 483228: 20 1 stack.c:125
1237224596: 483228: 20 1 ra=0x7d723c
1237224596: 483228: 16 1 stack.c:127
1237224596: 483228: 12 1 ssl_ciph.c:288
1237224596: 483228: 9 1 ra=0xd5388d
1237224596: 483228: 8 1 ra=0x7cb7ce
1237224596: 483228: 4 1 ra=0x7cb781

comment:8 Changed 11 years ago by nickm

So it looks like we're leaking not only the policies in this case, but the routerinfo_ts too. I am closing in on
you, bug 672!

comment:9 Changed 11 years ago by nickm

Oh hey. Line 3078 of routerlist.c. Shouldn't we be freeing the routerinfo_t there?

comment:10 Changed 11 years ago by nickm

Fixed and tested.

comment:11 Changed 11 years ago by nickm

flyspray2trac: bug closed.

comment:12 Changed 7 years ago by nickm

Component: Tor RelayTor
Note: See TracTickets for help on using tickets.