[tor-relays] Tor relay balks with "router_pick_published_address(): Success: chose address x.x.x.x"

Tobias Sachs tobias at tobiassachs.de
Tue Nov 8 23:43:00 UTC 2016


>> On 9 Nov. 2016, at 09:00, Tobias Sachs <tobias at tobiassachs.de> wrote:
>>
>> Hey,
>>
>> my Tor relay
>> https://atlas.torproject.org/#details/B567E8E39641F61091C1F2CAAAF73D3D1BF9CFE1
>> balks with the following message which is repeated in the log with the
>> "info" logging level up to 23251 times at the exact same millisecond.
> I assume you are talking about the router_pick_published_address
> message.
>
>> The relay responds at :9030/tor/server/authority with a 503 error.
> This is a temporary error when your relay is overloaded.
>
> I just tried
> http://167.114.245.102:9030/tor/server/authority
> and it delivered the descriptor fine, with no error.
Yes but this is a rare case during the day
Event,Date-Time,Reason,Duration,"Duration (in mins.)"
Up,"2016-11-07 22:29:47","Keyword Found","25 hrs, 13 mins",1514
Down,"2016-11-07 22:28:30","Keyword Not Found","0 hrs, 1 mins",1
Up,"2016-11-07 22:23:29","Keyword Found","0 hrs, 5 mins",5
Down,"2016-11-07 22:22:05","Keyword Not Found","0 hrs, 1 mins",1
Up,"2016-11-06 13:56:42","Keyword Found","32 hrs, 25 mins",1945
Down,"2016-11-06 13:55:44","Keyword Not Found","0 hrs, 0 mins",1
Up,"2016-11-06 13:22:19","Keyword Found","0 hrs, 33 mins",33
Down,"2016-11-06 13:21:21","Keyword Not Found","0 hrs, 0 mins",1
Up,"2016-11-06 13:17:31","Keyword Found","0 hrs, 3 mins",4
Down,"2016-11-06 13:16:33","Keyword Not Found","0 hrs, 0 mins",1

I don't know it but htop was something strange. The cpu was yellow which
is not documented and on 100%. The tor process itself had 0.0% cpu but
still traffic. Maybe this was a bug which was related to some upstream
kernel / package bugs. I rebooted the vm with the latest kernel and the
issue is gone. I let you aware if uptimetobot and statuscake still sees
some 503 errors.

>
> I logged a ticket:
>
> Relays should log a message when they return a 503 error to a client
> https://trac.torproject.org/projects/tor/ticket/20611
>
>> router_pick_published_address(): Success: chose address 'x.x.x.x'
> This message is not an error, it is a success.
>
> But I can see how it would be annoying:
>
> Rate limit router_pick_published_address log message
> https://trac.torproject.org/projects/tor/ticket/20610
>
>> This is a counting from the log with the corresponding timestamp.
>>
>> Nov 01 18:37:13.000 - 23251
>> Nov 01 18:37:22.000 - 59
>> Nov 01 18:38:17.000 - 23195
>> Nov 01 18:38:22.000 - 57
>> Nov 01 19:19:22.000 - 50
>> Nov 01 19:19:23.000 - 312
>> Nov 01 19:19:24.000 - 333
>> Nov 01 19:19:25.000 - 74
>> Nov 01 19:20:22.000 - 52
>> Nov 01 19:38:17.000 - 23207
>> Nov 01 20:38:17.000 - 23232
>>
>> 140 times exactly 49 repeats in around 2 hours.
>>
>> Interesting is that there is no error about this 503 error in the log
>> only my monitoring is aware of the issue.
>>
>> I hope you coul'd help me out with this issue.
> Maybe you should turn your log level down to notice?
> The less you log, the better.

I only used info log level to track down the issue with the 503 errors
because there were no log entry :)
Anyway thank you for opening the two tickets and your explanation.
>
> T
> This doesn't help you solve your problem, but it's relevant.
>
> I run Tor network simulations and see this all the time. I haven't taken
> the time to look into it, and always have assumed it's just a minor
> misconfiguration in the simulator or something that only exists
> _because_ it's a simulation.
>
> And ... it looks like teor swooped in and opened a ticket for the log spam.
>
> Matt

Nice to here that I am not alone and to help each other.

Best Regards
Tobias

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 819 bytes
Desc: OpenPGP digital signature
URL: <http://lists.torproject.org/pipermail/tor-relays/attachments/20161109/742a6d4a/attachment.sig>


More information about the tor-relays mailing list