Opened 9 years ago

Closed 9 years ago

Last modified 7 years ago

#1933 closed defect (invalid)

GETINFO requests trigger conn_read_callback events

Reported by: atagar Owned by:
Priority: Low Milestone:
Component: Core Tor/Tor Version:
Severity: Keywords: tor-relay
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

GETINFO requests are triggering the following DEBUG runlevel events: "conn_read_callback(): socket 15 wants to read.". Is this intentional?

This traces back to the 'connection_add' function of 'or/main.c', but after that the callers branch quite a bit so I'm not sure how it's connected to the control interface.

This causes a minor interface problem for arm since key presses trigger GETINFO calls but also are used to scroll the event log (ie, when the user presses 'up' at the DEBUG level it both scrolls up an entry and creates a new event, so they'll never get to the top).

This issue will partly go away when I refactor the connection panel to be independent of the main interface loop, but it still means arm and other controllers issuing periodic GETINFO calls are kinda noisy at the DEBUG level (accounting for instance triggers four GETINFO requests every ten seconds for accounting/* updates) so it would be nice if this was changed. However, if this is working as intended then I should probably filter these events out of the arm interface.

Tor version 0.2.2.13-alpha (oddly, this isn't among the version options...). Cheers! -Damian

Child Tickets

Change History (5)

comment:1 Changed 9 years ago by Sebastian

I think if you're displaying debug log level messages via controller that is kind of asking for trouble, especially on a busy node. It does seem to make sense imho that using the control port emits debug level message, as we might need to debug that at some point.

comment:2 Changed 9 years ago by nickm

Well, the log message is _correct_: the controller wrote the GETINFO command to the control socket, which caused the kernel to tell Tor, "Hey, socket 15 is now readable", so Tor has wound up in conn_read_callback (thanks to Libevent), and it is ready to read what the controller told it.

So the next question is, "Is it intentional that controllers can get DEBUG log messages that are caused by their own actions?" I think that's a "yes" too. The only case where we have deliberately stopped that from happening is in the CONN_LOG_PROTECT() cases in connection.c, which we added because we wanted to avoid infinite loops where sending a DEBUG message to a controller counted as a write an in turn caused other debug messages to get logged and sent to the controller.

It is certainly as-designed that the DEBUG log level is "kinda noisy".

So the last questions is, is there some reason the current behavior is incorrect?

comment:3 Changed 9 years ago by atagar

Resolution: invalid
Status: newclosed

Thanks, I kinda thought that might be the case. Ideally I'd like for arm to make minimal noise in the logs, but you're both right that at the DEBUG level this should be expected. Closing.

comment:4 Changed 7 years ago by nickm

Keywords: tor-relay added

comment:5 Changed 7 years ago by nickm

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