Skip to content

Log clearer message if TLS client connects to AMQP port #13559

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

Merged
merged 2 commits into from
Mar 17, 2025
Merged

Conversation

ansd
Copy link
Member

@ansd ansd commented Mar 17, 2025

What?

If a TLS client app is misconfigured trying to connect to AMQP port 5672 instead to the AMQPS port 5671, this commit makes RabbitMQ log a more descriptive error message.

openssl s_client -connect localhost:5672 -tls1_3
openssl s_client -connect localhost:5672 -tls1_2

RabbitMQ logs prior to this commit:

[info] <0.1073.0> accepting AMQP connection [::1]:53535 -> [::1]:5672
[error] <0.1073.0> closing AMQP connection <0.1073.0> ([::1]:53535 -> [::1]:5672, duration: '0ms'):
[error] <0.1073.0> {bad_header,<<22,3,1,0,192,1,0,0>>}

[info] <0.1080.0> accepting AMQP connection [::1]:53577 -> [::1]:5672
[error] <0.1080.0> closing AMQP connection <0.1080.0> ([::1]:53577 -> [::1]:5672, duration: '1ms'):
[error] <0.1080.0> {bad_header,<<22,3,1,0,224,1,0,0>>}

RabbitMQ logs after this commit:

[info] <0.969.0> accepting AMQP connection [::1]:53632 -> [::1]:5672
[error] <0.969.0> closing AMQP connection <0.969.0> ([::1]:53632 -> [::1]:5672, duration: '0ms'):
[error] <0.969.0> {detected_unexpected_tls_header,<<22,3,1,0,192,1,0,0>>

[info] <0.975.0> accepting AMQP connection [::1]:53638 -> [::1]:5672
[error] <0.975.0> closing AMQP connection <0.975.0> ([::1]:53638 -> [::1]:5672, duration: '1ms'):
[error] <0.975.0> {detected_unexpected_tls_header,<<22,3,1,0,224,1,0,0>>}

Why?

I've seen numerous occurrences in the past few years where misconfigured TLS apps connected to the wrong port. Therefore, RabbitMQ trying to detect a TLS client and providing a more descriptive log message seems appropriate to me.

How?

The first few bytes of any TLS connection are:

Record Type (1 byte):
Always 0x16 (22 in decimal) for a Handshake message.

Version (2 bytes):
This represents the highest version of TLS that the client supports. Common values: 0x0301 → TLS 1.0 (or SSL 3.1)
0x0302 → TLS 1.1
0x0303 → TLS 1.2
0x0304 → TLS 1.3

Record Length (2 bytes):
Specifies the length of the following handshake message.

Handshake Type (1 byte, usually the 6th byte overall): Always 0x01 for ClientHello.

 ## What?

If a TLS client app is misconfigured trying to connect to AMQP port 5672
instead to the AMQPS port 5671, this commit makes RabbitMQ log a more
descriptive error message.

```
openssl s_client -connect localhost:5672 -tls1_3
openssl s_client -connect localhost:5672 -tls1_2
```

RabbitMQ logs prior to this commit:
```
[info] <0.1073.0> accepting AMQP connection [::1]:53535 -> [::1]:5672
[error] <0.1073.0> closing AMQP connection <0.1073.0> ([::1]:53535 -> [::1]:5672, duration: '0ms'):
[error] <0.1073.0> {bad_header,<<22,3,1,0,192,1,0,0>>}

[info] <0.1080.0> accepting AMQP connection [::1]:53577 -> [::1]:5672
[error] <0.1080.0> closing AMQP connection <0.1080.0> ([::1]:53577 -> [::1]:5672, duration: '1ms'):
[error] <0.1080.0> {bad_header,<<22,3,1,0,224,1,0,0>>}
```

RabbitMQ logs after this commit:
```
[info] <0.969.0> accepting AMQP connection [::1]:53632 -> [::1]:5672
[error] <0.969.0> closing AMQP connection <0.969.0> ([::1]:53632 -> [::1]:5672, duration: '0ms'):
[error] <0.969.0> {detected_unexpected_tls_header,<<22,3,1,0,192,1,0,0>>

[info] <0.975.0> accepting AMQP connection [::1]:53638 -> [::1]:5672
[error] <0.975.0> closing AMQP connection <0.975.0> ([::1]:53638 -> [::1]:5672, duration: '1ms'):
[error] <0.975.0> {detected_unexpected_tls_header,<<22,3,1,0,224,1,0,0>>}
```

 ## Why?

I've seen numerous occurrences in the past few years where misconfigured TLS apps
connected to the wrong port. Therefore, RabbitMQ trying to detect a TLS client
and providing a more descriptive log message seems appropriate to me.

 ## How?

The first few bytes of any TLS connection are:

Record Type (1 byte):
Always 0x16 (22 in decimal) for a Handshake message.

Version (2 bytes):
This represents the highest version of TLS that the client supports. Common values:
0x0301 → TLS 1.0 (or SSL 3.1)
0x0302 → TLS 1.1
0x0303 → TLS 1.2
0x0304 → TLS 1.3

Record Length (2 bytes):
Specifies the length of the following handshake message.

Handshake Type (1 byte, usually the 6th byte overall):
Always 0x01 for ClientHello.
Copy link
Collaborator

@michaelklishin michaelklishin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Works as expected:

rabbitmq-diagnostics log_tail_stream
# => Streaming logs from node rabbit@{hostname} ...
# => 2025-03-17 18:23:36.919383-04:00 [info] <0.544.0> accepting # => AMQP connection [::1]:57812 -> [::1]:5672
# => 2025-03-17 18:23:36.919483-04:00 [error] <0.544.0> closing # => AMQP connection <0.544.0> ([::1]:57812 -> [::1]:5672, duration: '0ms'):
# => 2025-03-17 18:23:36.919483-04:00 [error] <0.544.0> {detected_unexpected_tls_header,<<22,3,1,0,224,1,0,0>>}

It also happens from time to time that HTTP clients use the wrong port
5672. Like for TLS clients connecting to 5672, RabbitMQ now prints a
more descriptive log message.

For example
```
curl http://localhost:5672
```
will log
```
[info] <0.946.0> accepting AMQP connection [::1]:57736 -> [::1]:5672
[error] <0.946.0> closing AMQP connection <0.946.0> ([::1]:57736 -> [::1]:5672, duration: '1ms'):
[error] <0.946.0> {detected_unexpected_http_header,<<"GET / HT">>}
```

We only check here for GET and not for all other HTTP methods, since
that's the most common case.
@michaelklishin michaelklishin added this to the 4.1.0 milestone Mar 17, 2025
@michaelklishin michaelklishin merged commit d5b8832 into main Mar 17, 2025
273 checks passed
@michaelklishin michaelklishin deleted the tls-header branch March 17, 2025 23:26
michaelklishin added a commit that referenced this pull request Mar 18, 2025
Log clearer message if TLS client connects to AMQP port (backport #13559)
ansd added a commit that referenced this pull request Mar 18, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
ansd added a commit that referenced this pull request Mar 18, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
mergify bot pushed a commit that referenced this pull request Mar 18, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```

(cherry picked from commit 5bfccba)
ansd added a commit that referenced this pull request Mar 18, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```

(cherry picked from commit 5bfccba)
michaelklishin pushed a commit that referenced this pull request Mar 19, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
ikavgo pushed a commit that referenced this pull request May 5, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
ikavgo pushed a commit that referenced this pull request May 5, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
ikavgo pushed a commit that referenced this pull request May 5, 2025
This is a follow up to #13559 addressing the feedback in
#13559 (comment)

The improved logs look as follows:
```
openssl s_client -connect localhost:5672 -tls1_3

[info] <0.946.0> accepting AMQP connection [::1]:49321 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49321 -> [::1]:5672 (duration: '0ms'):
[error] <0.946.0> TLS client detected on non-TLS AMQP port. Ensure the client is connecting to the correct port.
```

```
curl http://localhost:5672

[info] <0.954.0> accepting AMQP connection [::1]:49402 -> [::1]:5672
[error] <0.954.0> closing AMQP connection [::1]:49402 -> [::1]:5672 (duration: '0ms'):
[error] <0.954.0> HTTP GET request detected on AMQP port. Ensure the client is connecting to the correct port
```

```
telnet localhost 5672
Trying ::1...
Connected to localhost.
Escape character is '^]'.
hello

[info] <0.946.0> accepting AMQP connection [::1]:49664 -> [::1]:5672
[error] <0.946.0> closing AMQP connection [::1]:49664 -> [::1]:5672 (duration: '2s'):
[error] <0.946.0> client did not start with AMQP protocol header: <<"hello\r\n\r">>
```
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants