@@ -394,60 +394,69 @@ log_connection_exception(Name, ConnectedAt, Ex) ->
394394 connection_closed_abruptly -> warning ;
395395 _ -> error
396396 end ,
397- log_connection_exception (Severity , Name , ConnectedAt , Ex ).
397+ Duration = connection_duration (ConnectedAt ),
398+ log_connection_exception (Severity , Name , Duration , Ex ).
398399
399- log_connection_exception (Severity , Name , ConnectedAt , {heartbeat_timeout , TimeoutSec }) ->
400- ConnDuration = connection_duration (ConnectedAt ),
400+ log_connection_exception (Severity , Name , Duration , {heartbeat_timeout , TimeoutSec }) ->
401401 Fmt = " closing AMQP connection ~tp (~ts , duration: '~ts '):~n "
402402 " missed heartbeats from client, timeout: ~p s" ,
403403 % % Long line to avoid extra spaces and line breaks in log
404404 log_connection_exception_with_severity (Severity , Fmt ,
405- [self (), Name , ConnDuration , TimeoutSec ]);
406- log_connection_exception (Severity , Name , _ConnectedAt ,
405+ [self (), Name , Duration , TimeoutSec ]);
406+ log_connection_exception (Severity , Name , _Duration ,
407407 {connection_closed_abruptly ,
408408 # v1 {connection = # connection {user = # user {username = Username },
409409 vhost = VHost ,
410410 connected_at = ConnectedAt }}}) ->
411- ConnDuration = connection_duration (ConnectedAt ),
411+ Duration = connection_duration (ConnectedAt ),
412412 Fmt = " closing AMQP connection ~tp (~ts , vhost: '~ts ', user: '~ts ', duration: '~ts '):~n "
413413 " client unexpectedly closed TCP connection" ,
414414 log_connection_exception_with_severity (Severity , Fmt ,
415- [self (), Name , VHost , Username , ConnDuration ]);
415+ [self (), Name , VHost , Username , Duration ]);
416416% % when client abruptly closes connection before connection.open/authentication/authorization
417417% % succeeded, don't log username and vhost as 'none'
418- log_connection_exception (Severity , Name , ConnectedAt , {connection_closed_abruptly , _ }) ->
419- ConnDuration = connection_duration (ConnectedAt ),
418+ log_connection_exception (Severity , Name , Duration , {connection_closed_abruptly , _ }) ->
420419 Fmt = " closing AMQP connection ~tp (~ts , duration: '~ts '):~n "
421420 " client unexpectedly closed TCP connection" ,
422421 log_connection_exception_with_severity (Severity , Fmt ,
423- [self (), Name , ConnDuration ]);
422+ [self (), Name , Duration ]);
424423% % failed connection.tune negotiations
425- log_connection_exception (Severity , Name , ConnectedAt , {handshake_error , tuning ,
426- {exit , # amqp_error {explanation = Explanation },
427- _Method , _Stacktrace }}) ->
428- ConnDuration = connection_duration (ConnectedAt ),
424+ log_connection_exception (Severity , Name , Duration , {handshake_error , tuning ,
425+ {exit , # amqp_error {explanation = Explanation },
426+ _Method , _Stacktrace }}) ->
429427 Fmt = " closing AMQP connection ~tp (~ts ):~n "
430428 " failed to negotiate connection parameters: ~ts " ,
431- log_connection_exception_with_severity (Severity , Fmt , [self (), Name , ConnDuration , Explanation ]);
432- log_connection_exception (Severity , Name , ConnectedAt , {sasl_required , ProtocolId }) ->
433- ConnDuration = connection_duration (ConnectedAt ),
429+ log_connection_exception_with_severity (Severity , Fmt , [self (), Name , Duration , Explanation ]);
430+ log_connection_exception (Severity , Name , Duration , {sasl_required , ProtocolId }) ->
434431 Fmt = " closing AMQP 1.0 connection (~ts , duration: '~ts '): RabbitMQ requires SASL "
435432 " security layer (expected protocol ID 3, but client sent protocol ID ~b )" ,
436433 log_connection_exception_with_severity (Severity , Fmt ,
437- [Name , ConnDuration , ProtocolId ]);
434+ [Name , Duration , ProtocolId ]);
438435% % old exception structure
439- log_connection_exception (Severity , Name , ConnectedAt , connection_closed_abruptly ) ->
440- ConnDuration = connection_duration (ConnectedAt ),
436+ log_connection_exception (Severity , Name , Duration , connection_closed_abruptly ) ->
441437 Fmt = " closing AMQP connection ~tp (~ts , duration: '~ts '):~n "
442438 " client unexpectedly closed TCP connection" ,
443439 log_connection_exception_with_severity (Severity , Fmt ,
444- [self (), Name , ConnDuration ]);
445- log_connection_exception (Severity , Name , ConnectedAt , Ex ) ->
446- ConnDuration = connection_duration (ConnectedAt ),
440+ [self (), Name , Duration ]);
441+ log_connection_exception (Severity , Name , Duration , {bad_header , detected_tls }) ->
442+ Fmt = " closing AMQP connection ~ts (duration: '~ts '):~n "
443+ " TLS client detected on non-TLS AMQP port. "
444+ " Ensure the client is connecting to the correct port." ,
445+ log_connection_exception_with_severity (Severity , Fmt , [Name , Duration ]);
446+ log_connection_exception (Severity , Name , Duration , {bad_header , detected_http_get }) ->
447+ Fmt = " closing AMQP connection ~ts (duration: '~ts '):~n "
448+ " HTTP GET request detected on AMQP port. "
449+ " Ensure the client is connecting to the correct port." ,
450+ log_connection_exception_with_severity (Severity , Fmt , [Name , Duration ]);
451+ log_connection_exception (Severity , Name , Duration , {bad_header , Other }) ->
452+ Fmt = " closing AMQP connection ~ts (duration: '~ts '):~n "
453+ " client did not start with AMQP protocol header: ~p " ,
454+ log_connection_exception_with_severity (Severity , Fmt , [Name , Duration , Other ]);
455+ log_connection_exception (Severity , Name , Duration , Ex ) ->
447456 Fmt = " closing AMQP connection ~tp (~ts , duration: '~ts '):~n "
448457 " ~tp " ,
449458 log_connection_exception_with_severity (Severity , Fmt ,
450- [self (), Name , ConnDuration , Ex ]).
459+ [self (), Name , Duration , Ex ]).
451460
452461log_connection_exception_with_severity (Severity , Fmt , Args ) ->
453462 case Severity of
@@ -1118,18 +1127,16 @@ handle_input({frame_payload, Type, Channel, PayloadSize}, Data, State) ->
11181127 end ;
11191128handle_input (handshake , <<" AMQP" , A , B , C , D , Rest /binary >>, State ) ->
11201129 {Rest , version_negotiation ({A , B , C , D }, State )};
1130+ handle_input (handshake , <<" GET " , _URL /binary >>, # v1 {sock = Sock }) ->
1131+ % % Looks like an HTTP request.
1132+ refuse_connection (Sock , {bad_header , detected_http_get });
1133+ handle_input (handshake ,
1134+ <<16#16 , 16#03 , _Ver2 , _Len1 , _Len2 , 16#01 , _ /binary >>,
1135+ # v1 {sock = Sock }) ->
1136+ % % Looks like a TLS client hello.
1137+ refuse_connection (Sock , {bad_header , detected_tls });
11211138handle_input (handshake , <<Other :8 /binary , _ /binary >>, # v1 {sock = Sock }) ->
1122- Reason = case Other of
1123- <<16#16 , 16#03 , _Ver2 , _Len1 , _Len2 , 16#01 , _ , _ >> ->
1124- % % Looks like a TLS client hello.
1125- detected_unexpected_tls_header ;
1126- <<" GET " , _URL /binary >> ->
1127- % % Looks like an HTTP request.
1128- detected_unexpected_http_header ;
1129- _ ->
1130- bad_header
1131- end ,
1132- refuse_connection (Sock , {Reason , Other });
1139+ refuse_connection (Sock , {bad_header , Other });
11331140handle_input (Callback , Data , _State ) ->
11341141 throw ({bad_input , Callback , Data }).
11351142
@@ -1872,8 +1879,8 @@ get_client_value_detail(_Field, _ClientValue) ->
18721879 " " .
18731880
18741881connection_duration (ConnectedAt ) ->
1875- Now = os :system_time (milli_seconds ),
1876- DurationMillis = Now - ConnectedAt ,
1882+ Now = os :system_time (millisecond ),
1883+ DurationMillis = max ( 0 , Now - ConnectedAt ) ,
18771884 if
18781885 DurationMillis >= 1000 ->
18791886 DurationSecs = DurationMillis div 1000 ,
0 commit comments