Skip to content

Commit

Permalink
Log AMQP connection name and container-id (#11975)
Browse files Browse the repository at this point in the history
* Log AMQP connection name and container-id

Fixes #11958

 ## What
Log container-id and connection name.
Example JSON log:
```
{"time":"2024-08-12 10:49:44.365724+02:00","level":"info","msg":"accepting AMQP connection [::1]:56754 -> [::1]:5672","pid":"<0.1164.0>","domain":"rabbitmq.connection"}
{"time":"2024-08-12 10:49:44.381244+02:00","level":"debug","msg":"User 'guest' authenticated successfully by backend rabbit_auth_backend_internal","pid":"<0.1164.0>","domain":"rabbitmq","connection":"[::1]:56754 -> [::1]:5672"}
{"time":"2024-08-12 10:49:44.381578+02:00","level":"info","msg":"AMQP 1.0 connection from container 'my container ID': user 'guest' authenticated and granted access to vhost '/'","pid":"<0.1164.0>","domain":"rabbitmq.connection","connection":"[::1]:56754 -> [::1]:5672","container_id":"my container ID"}
{"time":"2024-08-12 10:49:44.381654+02:00","level":"debug","msg":"AMQP 1.0 connection.open frame: hostname = localhost, extracted vhost = /, idle-time-out = {uint,\n                                                                                            30000}","pid":"<0.1164.0>","domain":"rabbitmq","connection":"[::1]:56754 -> [::1]:5672","container_id":"my container ID"}
{"time":"2024-08-12 10:49:44.386412+02:00","level":"debug","msg":"AMQP 1.0 created session process <0.1170.0> for channel number 0","pid":"<0.1164.0>","domain":"rabbitmq","connection":"[::1]:56754 -> [::1]:5672","container_id":"my container ID"}

{"time":"2024-08-12 10:49:46.387957+02:00","level":"debug","msg":"AMQP 1.0 closed session process <0.1170.0> with channel number 0","pid":"<0.1164.0>","domain":"rabbitmq","connection":"[::1]:56754 -> [::1]:5672","container_id":"my container ID"}
{"time":"2024-08-12 10:49:46.388201+02:00","level":"info","msg":"closing AMQP connection ([::1]:56754 -> [::1]:5672)","pid":"<0.1164.0>","domain":"rabbitmq.connection","connection":"[::1]:56754 -> [::1]:5672","container_id":"my container ID"}
```

If JSON logging is not used, this commit still includes the container-ID
once at info level:
```
2024-08-12 10:48:57.451580+02:00 [info] <0.1164.0> accepting AMQP connection [::1]:56715 -> [::1]:5672
2024-08-12 10:48:57.465924+02:00 [debug] <0.1164.0> User 'guest' authenticated successfully by backend rabbit_auth_backend_internal
2024-08-12 10:48:57.466289+02:00 [info] <0.1164.0> AMQP 1.0 connection from container 'my container ID': user 'guest' authenticated and granted access to vhost '/'
2024-08-12 10:48:57.466377+02:00 [debug] <0.1164.0> AMQP 1.0 connection.open frame: hostname = localhost, extracted vhost = /, idle-time-out = {uint,
2024-08-12 10:48:57.466377+02:00 [debug] <0.1164.0>                                                                                             30000}
2024-08-12 10:48:57.470800+02:00 [debug] <0.1164.0> AMQP 1.0 created session process <0.1170.0> for channel number 0

2024-08-12 10:48:59.472928+02:00 [debug] <0.1164.0> AMQP 1.0 closed session process <0.1170.0> with channel number 0
2024-08-12 10:48:59.473332+02:00 [info] <0.1164.0> closing AMQP connection ([::1]:56715 -> [::1]:5672)
```

 ## Why?
See #11958 and https://www.rabbitmq.com/docs/connections#client-provided-names

To provide a similar feature to AMQP 0.9.1 this commit uses container-id as sent by the client in the open frame.
> Examples of containers are brokers and client applications.

The advantage is that the `container-id` is mandatory. Hence, in AMQP 1.0, we can enforce the desired behaviour that we document on our website for AMQP 0.9.1:
> The name is optional; however, developers are strongly encouraged to provide one as it would significantly simplify certain operational tasks.

* Clarify that container refers to AMQP 1.0

Rename container_id to amqp_container and change log message such that
it's unambigious that the word "container" refers to AMQP 1.0 containers
(to reduce confusion with the meaning of "container" in Docker / Kubernetes).
  • Loading branch information
ansd committed Aug 12, 2024
1 parent 2db84be commit 10a309d
Showing 1 changed file with 7 additions and 4 deletions.
11 changes: 7 additions & 4 deletions deps/rabbit/src/rabbit_amqp_reader.erl
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,7 @@ unpack_from_0_9_1(
{Sock,RecvLen, PendingRecv, SupPid, Buf, BufLen, ProxySocket,
ConnectionName, Host, PeerHost, Port, PeerPort, ConnectedAt},
Parent, HandshakeTimeout) ->
logger:update_process_metadata(#{connection => ConnectionName}),
#v1{parent = Parent,
sock = Sock,
callback = handshake,
Expand Down Expand Up @@ -380,7 +381,8 @@ parse_frame_body(Body, _Channel) ->
end.

handle_connection_frame(
#'v1_0.open'{max_frame_size = ClientMaxFrame,
#'v1_0.open'{container_id = {utf8, ContainerId},
max_frame_size = ClientMaxFrame,
channel_max = ClientChannelMax,
idle_time_out = IdleTimeout,
hostname = Hostname,
Expand All @@ -390,7 +392,7 @@ handle_connection_frame(
user = User = #user{username = Username}},
helper_sup = HelperSupPid,
sock = Sock} = State0) ->

logger:update_process_metadata(#{amqp_container => ContainerId}),
Vhost = vhost(Hostname),
ok = check_user_loopback(State0),
ok = check_vhost_exists(Vhost, State0),
Expand All @@ -402,8 +404,9 @@ handle_connection_frame(
rabbit_core_metrics:auth_attempt_succeeded(<<>>, Username, amqp10),
notify_auth(user_authentication_success, Username, State0),
rabbit_log_connection:info(
"AMQP 1.0 connection: user '~ts' authenticated and granted access to vhost '~ts'",
[Username, Vhost]),
"Connection from AMQP 1.0 container '~ts': user '~ts' "
"authenticated and granted access to vhost '~ts'",
[ContainerId, Username, Vhost]),

OutgoingMaxFrameSize = case ClientMaxFrame of
undefined ->
Expand Down

0 comments on commit 10a309d

Please sign in to comment.