From 41315bff0d8904039d8eb4a52765203cfb2b69b9 Mon Sep 17 00:00:00 2001 From: terry-xiaoyu <506895667@qq.com> Date: Thu, 15 Nov 2018 23:12:36 +0800 Subject: [PATCH] Log macros for lazy evaluation --- include/logger.hrl | 17 +++++++++++++++++ src/emqx_connection.erl | 14 +++++--------- src/emqx_protocol.erl | 22 +++++----------------- src/emqx_ws_connection.erl | 33 +++++++++++++++------------------ 4 files changed, 42 insertions(+), 44 deletions(-) create mode 100644 include/logger.hrl diff --git a/include/logger.hrl b/include/logger.hrl new file mode 100644 index 000000000..2f13ddbb9 --- /dev/null +++ b/include/logger.hrl @@ -0,0 +1,17 @@ +%%-------------------------------------------------------------------- +%% Logs with header +%%-------------------------------------------------------------------- +-ifdef(LOG_HEADER). +%% with header +-define(LOG(Level, Format, Args), + begin + (emqx_logger:Level(#{},#{report_cb => + fun(_) -> + {?LOG_HEADER ++ " "++ (Format), (Args)} + end})) + end). +-else. +%% without header +-define(LOG(Level, Format, Args), + emqx_logger:Level(Format, Args)). +-endif. \ No newline at end of file diff --git a/src/emqx_connection.erl b/src/emqx_connection.erl index 9118933ef..97a2c91bb 100644 --- a/src/emqx_connection.erl +++ b/src/emqx_connection.erl @@ -16,8 +16,11 @@ -behaviour(gen_server). +-define(LOG_HEADER, "[TCP]"). + -include("emqx.hrl"). -include("emqx_mqtt.hrl"). +-include("logger.hrl"). -export([start_link/3]). -export([info/1, attrs/1]). @@ -50,13 +53,6 @@ -define(SOCK_STATS, [recv_oct, recv_cnt, send_oct, send_cnt, send_pend]). --define(LOG(Level, Format, Args), - emqx_logger:Level(#{header => "[TCP] ", format => Format, args => Args}, - #{report_cb => - fun(#{header := Hdr0, format := Fmt0, args := Args0}) -> - {Hdr0 ++ Fmt0, Args0} - end})). - start_link(Transport, Socket, Options) -> {ok, proc_lib:spawn_link(?MODULE, init, [[Transport, Socket, Options]])}. @@ -135,7 +131,7 @@ init([Transport, RawSocket, Options]) -> PubLimit = init_limiter(emqx_zone:get_env(Zone, publish_limit)), EnableStats = emqx_zone:get_env(Zone, enable_stats, true), IdleTimout = emqx_zone:get_env(Zone, idle_timeout, 30000), - SendFun = send_fun(Transport, Socket, Peername), + SendFun = send_fun(Transport, Socket), ProtoState = emqx_protocol:init(#{peername => Peername, sockname => Sockname, peercert => Peercert, @@ -169,7 +165,7 @@ init_limiter(undefined) -> init_limiter({Rate, Burst}) -> esockd_rate_limit:new(Rate, Burst). -send_fun(Transport, Socket, Peername) -> +send_fun(Transport, Socket) -> fun(Packet, Options) -> Data = emqx_frame:serialize(Packet, Options), try Transport:async_send(Socket, Data) of diff --git a/src/emqx_protocol.erl b/src/emqx_protocol.erl index 904b158ab..23710b76c 100644 --- a/src/emqx_protocol.erl +++ b/src/emqx_protocol.erl @@ -14,8 +14,11 @@ -module(emqx_protocol). +-define(LOG_HEADER, "[MQTT]"). + -include("emqx.hrl"). -include("emqx_mqtt.hrl"). +-include("logger.hrl"). -export([init/2]). -export([info/1]). @@ -72,13 +75,6 @@ -define(NO_PROPS, undefined). --define(LOG(Level, Format, Args), - emqx_logger:Level(#{header => "[MQTT] ", format => Format, args => Args}, - #{report_cb => - fun(#{header := Hdr0, format := Fmt0, args := Args0}) -> - {Hdr0 ++ Fmt0, Args0} - end})). - %%------------------------------------------------------------------------------ %% Init %%------------------------------------------------------------------------------ @@ -810,17 +806,9 @@ check_sub_acl(TopicFilters, PState) -> end, {ok, []}, TopicFilters). trace(recv, Packet) -> - emqx_logger:debug(#{header => "[MQTT] RECV ~s", pck => Packet}, - #{report_cb => - fun(#{header := Fmt, pck := Pckt}) -> - {Fmt, [emqx_packet:format(Pckt)]} - end}); + ?LOG(debug, "RECV ~s", [emqx_packet:format(Packet)]); trace(send, Packet) -> - emqx_logger:debug(#{header => "[MQTT] SEND ~s", pck => Packet}, - #{report_cb => - fun(#{header := Fmt, pck := Pckt}) -> - {Fmt, [emqx_packet:format(Pckt)]} - end}). + ?LOG(debug, "SEND ~s", [emqx_packet:format(Packet)]). inc_stats(recv, Type, PState = #pstate{recv_stats = Stats}) -> PState#pstate{recv_stats = inc_stats(Type, Stats)}; diff --git a/src/emqx_ws_connection.erl b/src/emqx_ws_connection.erl index fd421dde5..763aa182e 100644 --- a/src/emqx_ws_connection.erl +++ b/src/emqx_ws_connection.erl @@ -14,8 +14,11 @@ -module(emqx_ws_connection). +-define(LOG_HEADER, "[WS]"). + -include("emqx.hrl"). -include("emqx_mqtt.hrl"). +-include("logger.hrl"). -export([info/1, attrs/1]). -export([stats/1]). @@ -45,12 +48,6 @@ -define(SOCK_STATS, [recv_oct, recv_cnt, send_oct, send_cnt]). --define(WSLOG(Level, Format, Args), - emqx_logger:Level(#{header => "[WS] ", format => Format, args => Args}, - #{report_cb => - fun(#{header := Hdr0, format := Fmt0, args := Args0}) -> - {Hdr0 ++ Fmt0, Args0} - end})). %%------------------------------------------------------------------------------ %% API %%------------------------------------------------------------------------------ @@ -169,7 +166,7 @@ websocket_handle({binary, Data}, State = #state{parser_state = ParserState, proto_state = ProtoState}) -> BinSize = iolist_size(Data), put(recv_oct, get(recv_oct) + BinSize), - ?WSLOG(debug, "RECV ~p", [Data]), + ?LOG(debug, "RECV ~p", [Data]), emqx_metrics:inc('bytes/received', BinSize), case catch emqx_frame:parse(iolist_to_binary(Data), ParserState) of {more, NewParserState} -> @@ -181,7 +178,7 @@ websocket_handle({binary, Data}, State = #state{parser_state = ParserState, {ok, ProtoState1} -> websocket_handle({binary, Rest}, reset_parser(State#state{proto_state = ProtoState1})); {error, Error} -> - ?WSLOG(error, "Protocol error - ~p", [Error]), + ?LOG(error, "Protocol error - ~p", [Error]), stop(Error, State); {error, Reason, ProtoState1} -> shutdown(Reason, State#state{proto_state = ProtoState1}); @@ -189,10 +186,10 @@ websocket_handle({binary, Data}, State = #state{parser_state = ParserState, stop(Error, State#state{proto_state = ProtoState1}) end; {error, Error} -> - ?WSLOG(error, "Frame error: ~p", [Error]), + ?LOG(error, "Frame error: ~p", [Error]), stop(Error, State); {'EXIT', Reason} -> - ?WSLOG(error, "Frame error:~p~nFrame data: ~p", [Reason, Data]), + ?LOG(error, "Frame error:~p~nFrame data: ~p", [Reason, Data]), shutdown(parse_error, State) end. @@ -230,12 +227,12 @@ websocket_info({timeout, Timer, emit_stats}, {ok, State#state{stats_timer = undefined}, hibernate}; websocket_info({keepalive, start, Interval}, State) -> - ?WSLOG(debug, "Keepalive at the interval of ~p", [Interval]), + ?LOG(debug, "Keepalive at the interval of ~p", [Interval]), case emqx_keepalive:start(stat_fun(), Interval, {keepalive, check}) of {ok, KeepAlive} -> {ok, State#state{keepalive = KeepAlive}}; {error, Error} -> - ?WSLOG(warning, "Keepalive error - ~p", [Error]), + ?LOG(warning, "Keepalive error - ~p", [Error]), shutdown(Error, State) end; @@ -244,19 +241,19 @@ websocket_info({keepalive, check}, State = #state{keepalive = KeepAlive}) -> {ok, KeepAlive1} -> {ok, State#state{keepalive = KeepAlive1}}; {error, timeout} -> - ?WSLOG(debug, "Keepalive Timeout!", []), + ?LOG(debug, "Keepalive Timeout!", []), shutdown(keepalive_timeout, State); {error, Error} -> - ?WSLOG(warning, "Keepalive error - ~p", [Error]), + ?LOG(warning, "Keepalive error - ~p", [Error]), shutdown(keepalive_error, State) end; websocket_info({shutdown, discard, {ClientId, ByPid}}, State) -> - ?WSLOG(warning, "discarded by ~s:~p", [ClientId, ByPid]), + ?LOG(warning, "discarded by ~s:~p", [ClientId, ByPid]), shutdown(discard, State); websocket_info({shutdown, conflict, {ClientId, NewPid}}, State) -> - ?WSLOG(warning, "clientid '~s' conflict with ~p", [ClientId, NewPid]), + ?LOG(warning, "clientid '~s' conflict with ~p", [ClientId, NewPid]), shutdown(conflict, State); websocket_info({binary, Data}, State) -> @@ -266,13 +263,13 @@ websocket_info({shutdown, Reason}, State) -> shutdown(Reason, State); websocket_info(Info, State) -> - ?WSLOG(error, "unexpected info: ~p", [Info]), + ?LOG(error, "unexpected info: ~p", [Info]), {ok, State}. terminate(SockError, _Req, #state{keepalive = Keepalive, proto_state = ProtoState, shutdown = Shutdown}) -> - ?WSLOG(debug, "Terminated for ~p, sockerror: ~p", + ?LOG(debug, "Terminated for ~p, sockerror: ~p", [Shutdown, SockError]), emqx_keepalive:cancel(Keepalive), case {ProtoState, Shutdown} of