Merge TLS debug branch

We need to have better TLS debugging support in the normal Tor

I propose that we merge nick's branch and create an off-by-default option: https://gitweb.torproject.org/nickm/tor.git/shortlog/refs/heads/loud_ssl_states

Perhaps "LoudSSLState" and have it off by default.

changed milestone to %Tor: 0.2.3.x-final

added component::core tor/tor milestone::Tor: 0.2.3.x-final owner::arma priority::medium resolution::fixed status::closed tor-client type::enhancement labels

I wonder why nickm's branch says "NOT FOR MERGE INTO MASTER."

Is it just because it would be noisy? Or is there some compatibility or performance thing?

I would go with 'DebugSSLState' so it can do more stuff later with the same config option name.

Trac:
Milestone: N/A to Tor: 0.2.3.x-final

That seems reasonable - lets wait for nick to comment?

Don't remember why I tagged it as not-for-merge; I expect that it's the combination of being really noisy, poor-for-performance, and always-on.

It's not a great way to actually diagnose this stuff. What we typically want is not a log of every transition, but instead some way to track what state connections get to before they die. IOW, if we go A->B, B->C, then never get to D, then the interesting fact is "we never got past C", not "We got to A! We got to B!" I think we might have a ticket for that.

Replying to nickm:

It's not a great way to actually diagnose this stuff. What we typically want is not a log of every transition, but instead some way to track what state connections get to before they die. IOW, if we go A->B, B->C, then never get to D, then the interesting fact is "we never got past C", not "We got to A! We got to B!" I think we might have a ticket for that.

#3116 (moved)

Cleaned up code and threw threw the messages into the "handshake" domain so you can say stuff like

tor -Log "notice [handshake]debug stdout"

See branch bug3264 in my public repository.

Trac:
Status: new to needs_review

Looks plausible.

I guess there can be only one ssl callback at a time, so you either register your function directly if there isn't one, or call your function from within the other callback if there is?

So to be clear, these debug messages are on-by-default with no way to not see them. Is that ok? The original ticket suggested a config option which is off-by-default.

Replying to arma:

Looks plausible.

I guess there can be only one ssl callback at a time, so you either register your function directly if there isn't one, or call your function from within the other callback if there is?

Right.

So to be clear, these debug messages are on-by-default with no way to not see them. Is that ok? The original ticket suggested a config option which is off-by-default.

There is a way not to see them: Don't enable debug-level handshake-domain messages. If you are only logging at info, you're fine. I think that the original ticket had been written without realizing that log domains already did everything we need here.

Replying to nickm:

So to be clear, these debug messages are on-by-default with no way to not see them. Is that ok? The original ticket suggested a config option which is off-by-default.

There is a way not to see them: Don't enable debug-level handshake-domain messages. If you are only logging at info, you're fine. I think that the original ticket had been written without realizing that log domains already did everything we need here.

But if you log at debug, you get them and there's no way to not get them (except through a complex non-standard log line where you ask for every domain but handshake)?

How many debug lines are we talking about here, for a fast relay?

I think the original ticket wanted to see them at log-level debug if the config option was on, and not at all if the config option was off. He wasn't hoping to see them at notice if the config option was on. The goal is to avoid making it impractical to run your relay at log-level debug.

Jake, please let me know whether I'm parroting you correctly.

Replying to arma:

Replying to nickm:

So to be clear, these debug messages are on-by-default with no way to not see them. Is that ok? The original ticket suggested a config option which is off-by-default.

There is a way not to see them: Don't enable debug-level handshake-domain messages. If you are only logging at info, you're fine. I think that the original ticket had been written without realizing that log domains already did everything we need here.

But if you log at debug, you get them and there's no way to not get them (except through a complex non-standard log line where you ask for every domain but handshake)?

"Nonstandard" how? Logging at debug is already nonstandard.

Just say "Log [handshake]debug file /var/log/debug.log" if you don't want these.

How many debug lines are we talking about here, for a fast relay?

We're looking at maybe 10-20 lines per connection. Probably small in comparison to the "flushed %d bytes, %d ready to flush, %d remain" and "Read %ld bytes. %d on inbuf" messages.

I think the original ticket wanted to see them at log-level debug if the config option was on, and not at all if the config option was off. He wasn't hoping to see them at notice if the config option was on.

Sure, but we aren't bound by the original ticket. We're allowed to implement stuff using the infrastructure we already have, rather than proliferating ways to enable/disable sets of log messages.

The goal is to avoid making it impractical to run your relay at log-level debug.

I think we meet that goal. If not, let's scrap this and just build #3116 (moved).

I think it's fine to log at debug level - the key thing is merely to log all of this information at some level without having the user bust out tcpdump.

Replying to ioerror:

I think it's fine to log at debug level

Ok. Sounds great.

Ok, merging.

Trac:
Resolution: N/A to fixed
Status: needs_review to closed

Trac:
Keywords: N/A deleted, tor-client added

Trac:
Component: Tor Client to Tor

closed

moved to tpo/core/tor#3264 (closed)