Every few hours, relays [warn] Received circuit padding stop command for unknown machine.

toralf says on #tor-relays:

I got 5x within last 36 ours with 0.4.1.1-alpha:  [warn] Received circuit padding stop command for unknown machine.        -shall I ignore that?

I'm marking this as 041-must, because we will get lots of bug reports from relay operators if we release a stable with this warning. At the very least, we must downgrade it to a protocol error.

changed milestone to %Tor: 0.4.0.x-final

added 040-backport actualpoints::1 circuitpadding component::core tor/tor consider-backport-after-0415 milestone::Tor: 0.4.0.x-final owner::mikeperry points::1 priority::medium resolution::fixed reviewer::asn severity::normal sponsor::2 status::closed teor-merge tor-relay type::defect version::tor 0.4.0.1-alpha wtf-pad labels

This is interesting. The actual log is due refactoring eliminating a return value propogation/check of free_circ_machine_infos_with_machinenum() in circpad_handle_padding_negotiate(). As a result of the check being removed, the logline is always printing even if the machine is valid and did exist. So adding the check back in will eliminate most of those.

It's not happening that often because normally client-side does not send STOP commands. The client will only send a STOP of the machine conditions cease applying. This can happen in the event of a circuit build timeout (and associated purpose change to MEASUREMENT), though.

So I think all we have to do is make free_circ_machine_infos_with_machinenum() return a success/fail result, and check it properly in circpad_handle_padding_negotiate(), before warning.

Trac:
Owner: N/A to mikeperry
Status: new to accepted

If the relay operator can't do anything to fix these warnings, we should downgrade the remaining warnings to protocol warnings.

Fix as per comment:1 https://github.com/torproject/tor/pull/1063

Trac:
Status: accepted to needs_review

I have some questions about the latest commit: some of the changes look like typos?

Trac:
Status: needs_review to needs_revision

Can you be more specific? Do you mean the origin-side messages? I changed those from LD_PROTOCOL because I think they should be LD_CIRC. But they are not relay side, they are origin side. It's my understanding that relay side messages are what LOG_PROTOCOL_WARN is for.

LOG_PROTOCOL_WARN Is for warnings about other nodes on the network disobeying the tor protocol.

So it should also be used for log messages on the origin side, when the message is caused by the relay behaving badly.

Hrmm.. but there is something that origins can do.. They can use ExcludeNodes to blacklist nodes that violoate protocol. Based on the reasoning for having LOG_PROTOCOL_WARN, it sounds like origin-facing procotol warns that mention the idhex and recommend ExcludeNodes should be fine as regular warns.

The reasoning is that I think that some users would prefer having padding defenses work over using broken nodes that violate protocol. Right now, circpad does not kill the circuit if padding fails in a bizarre way. I am thinking it should, or at least should tell the user and advise them.

This ticket got a lot more complicated than fixing this bug.. Should we make a different ticket about the warns?

Replying to mikeperry:

Hrmm.. but there is something that origins can do.. They can use ExcludeNodes to blacklist nodes that violoate protocol. Based on the reasoning for having LOG_PROTOCOL_WARN, it sounds like origin-facing procotol warns that mention the idhex and recommend ExcludeNodes should be fine as regular warns.

I think you should talk to the Tor Browser team and UX team about this kind of warning. It could confuse a lot of Tor Browser users.

The reasoning is that I think that some users would prefer having padding defenses work over using broken nodes that violate protocol. Right now, circpad does not kill the circuit if padding fails in a bizarre way. I am thinking it should, or at least should tell the user and advise them.

We need to design tor for the majority of our users, who do not edit their torrcs. But we also need to have advanced options available for users who need strict privacy. I don't know if there's a way to do both: we should talk to the UX team.

This ticket got a lot more complicated than fixing this bug.. Should we make a different ticket about the warns?

Yes, I think so.

I pushed more log protocol warn updates to the PR: now when padding negotiation fails due to either corrupt cell or "valid" refusal, we LOG_PROTOCOL_WARN. Those should not happen, but one of them was at info, so it was already quiet.

I will file a new ticket for evaluating if the origin-side LOG_PROTOCOL_WARNs here should be LOG_WARNs or not.

Trac:
Status: needs_revision to needs_review

Trac:
Reviewer: N/A to asn

Seems reasonable. Please see my commit in https://github.com/torproject/tor/pull/1101.

I added a log for receiving a legit STOP command, and also promoted a protocol warn for receiving a padding from the wrong hop to a normal warn. I think if this happens we want to learn about it.

Setting to needs_rev as its waiting for action.

Trac:
Status: needs_review to needs_revision

Asn's changes are fine with me. I'm not the reviewer though, so just setting back to needs_review.

Trac:
Status: needs_revision to needs_review

OK, since mike ACKed it I'm moving it to merge_ready.

Trac:
Status: needs_review to merge_ready

Merged to 0.4.1 and forward.

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

A relay operator (strelnikov) reports getting this message on their 0.4.0.5 relay.

It looks like commit 9aaf72ea went into 0.4.0.1-alpha?

So (a) the bug is in our stable, and here is a user reporting it like teor predicted, and (b) we only pushed the fix into 0.4.1 above, right?

Reopening so it can get more eyes. Thanks!

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