Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log tls handshake timeouts #11171

Open
lukebakken opened this issue May 5, 2024 · 3 comments · Fixed by #11176
Open

Log tls handshake timeouts #11171

lukebakken opened this issue May 5, 2024 · 3 comments · Fixed by #11176
Assignees

Comments

@lukebakken
Copy link
Collaborator

lukebakken commented May 5, 2024

Is your feature request related to a problem? Please describe.

https://groups.google.com/g/rabbitmq-users/c/VT4GKJVJT7s

In the above discussion, the user reported that their ESP8266 device wouldn't connect to RabbitMQ when the following server settings are enabled:

ssl_options.verify = verify_peer
ssl_options.fail_if_no_peer_cert = true

If the above verification is disabled, the connection succeeds. It turns out that ssl:handshake took longer than the default 5 second timeout set by the ssl_handshake_timeout setting. I determined this by using redbug, because NOTHING was logged by RabbitMQ! 🤦‍♂️

Describe the solution you'd like

RabbitMQ should clearly log TLS errors like handshake timeouts.

@lukebakken lukebakken self-assigned this May 5, 2024
@lukebakken
Copy link
Collaborator Author

lukebakken commented May 5, 2024

@ansd you might find this interesting. When the TLS handshake times out, this is what rabbit_mqtt_reader:init/1 returns:

1> redbug:start("rabbit_mqtt_reader:init->return,stack",[{time,60000}]).
{529,1}

% 10:21:43 <0.791.0>({rabbit_mqtt_reader,init,1})
% rabbit_mqtt_reader:init({acceptor,{0,0,0,0,0,0,0,0},8883})
%   proc_lib:init_p_do_apply/3
                                                                                                                                                                                    % 10:21:43 <0.791.0>(dead)
% rabbit_mqtt_reader:init/1 -> {exit,normal}

I'm assuming this is why nothing is logged ... I'm continuing my investigation. I'm kind of surprised a badmatch is getting turned into {exit, normal} somehow 🤔

UPDATE: oh, here's why:

(rabbit@PROKOFIEV)4> redbug:start("rabbit_networking:handshake->return,stack",[{time,60000}]).
{529,1}

% 10:29:05 <0.774.0>({rabbit_mqtt_reader,init,1})
% rabbit_networking:handshake({acceptor,{0,0,0,0,0,0,0,0},8883}, false)
%   rabbit_mqtt_reader:init/1
%   proc_lib:init_p_do_apply/3

% 10:29:05 <0.774.0>(dead)
% rabbit_networking:handshake/2 -> {exit,normal}

UPDATE 2: yeah, it seems like the whole supervisor setup for a TCP/SSL ranch listener swallows errors like TLS handshake timeout, with nary a log message or crash anywhere.

lukebakken added a commit that referenced this issue May 6, 2024
Fixes #11171

An MQTT user encountered TLS handshake timeouts with their IoT device,
and the actual error from `ssl:handshake` / `ranch:handshake` was not
caught and logged.

At this time, `ranch` uses `exit(normal)` in the case of timeouts, but
that should change in the future
(ninenines/ranch#336)
@lukebakken lukebakken reopened this Sep 13, 2024
@lukebakken
Copy link
Collaborator Author

Re-opening since #12304 reverted #11176.

@lukebakken
Copy link
Collaborator Author

lukebakken commented Sep 13, 2024

This issue would be helped by having ninenines/ranch#336 addressed in Ranch.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant