Logs to ELK

[eliteaz]

as I understand ejabberd uses standard Erlang logging output I would like to know if there is any solution ejbberd service error and crash logs send to elastic or journalctl ? even i see that info notices is sending to journal.

[logicwonder]

This would be a great feature addition. A structured log format that could be parsed using a grok expression would be ideal for logstash. The eJabberd.log, error.log and crash.log formats may be allowed to be user defined in configuration.

[badlop]

Quick patch to send to journald:

From 5ff3a4f14d613eef0a9c19e7d56f42a3cd498cc4 Mon Sep 17 00:00:00 2001
From: Badlop <[email protected]>
Date: Wed, 25 May 2022 03:10:04 +0200
Subject: [PATCH] Add logger_journald library and send to journald

View 'info' and higher priority log entries in real time:
  journalctl -f -p 6 -t ejabberd
---
 rebar.config            | 1 +
 src/ejabberd_logger.erl | 3 +++
 2 files changed, 4 insertions(+)

diff --git a/rebar.config b/rebar.config
index 6db4fe2fc..c0a7e844c 100644
--- a/rebar.config
+++ b/rebar.config
@@ -45,6 +45,7 @@
         {if_version_below, "22",
          {lager, ".*", {git, "https://github.com/erlang-lager/lager", {tag, "3.9.1"}}}
         },
+        {logger_journald, ".*", {git, "https://github.com/seriyps/logger_journald", {tag, "0.3.0"}}},
         {if_var_true, lua,
          {if_not_rebar3,
           {luerl, ".*", {git, "https://github.com/rvirding/luerl", {tag, "1.0"}}}
diff --git a/src/ejabberd_logger.erl b/src/ejabberd_logger.erl
index e4fe34e0e..82ff185b5 100644
--- a/src/ejabberd_logger.erl
+++ b/src/ejabberd_logger.erl
@@ -294,6 +294,9 @@ start(Level) ->
 	    ok -> ok;
 	    {error, {already_exist, _}} -> ok
 	end,
+        logger:add_handler(journald_log, logger_journald_h,
+                   #{level => all,
+                     config => #{defaults => #{"SYSLOG_IDENTIFIER" => ejabberd}}}),
 	case logger:add_handler(ejabberd_log, logger_std_h,
 				#{level => all,
 				  config => Config#{file => EjabberdLog},
-- 
2.34.1

[logicwonder]

Currently I am parsing the eJabberd logs in realtime and preparing logs in structured format compatible with Logstash. However the structure of the log needs to be such that every event in the log is contained in a single line. But the log record for mod_http_api request is spanning multiple lines as there are new lines used for formatting. See an example below:

2022-06-24 16:57:45.511712+05:30 [info] <0.13521.2285>@mod_http_api:log/3:511 API call change_password [{<<"host">>,<<"xxxx.xxxx.xxx.xxx">>}, {<<"newpass">>, <<"xxxxxxxxxxxxxxxxxxxx">>}, {<<"user">>,<<"yyyyyyyyyyyyy">>}] from ::ffff:xxxx.xxx.xxx.xxx:62004

2022-06-24 16:56:23.005693+05:30 [info] <0.15324.1512>@mod_http_api:log/3:511 API call stats_host [{<<"host">>,<<"xxxx.xxxx.xxx.xx">>}, {<<"name">>,<<"onlineusers">>}] from ::ffff:xxxx.xxx.xxx.xxx:36668

It would be great if the log is made parsable by wrapping this into a single line. A basic setting for log format with values like standard, pretty etc. would be a great feature.

[badlop]

Currently I am parsing the eJabberd logs in realtime and preparing logs in structured format compatible with Logstash.

Did you check if there are libraries that already provide that feature? Maybe one of those is useful for that case:

https://hex.pm/packages?search=logstash&sort=recent_downloads

every event in the log is contained in a single line

Apparently, if we want the log line to contain pretty-printed strings like <<"host">>, the code must use ~p, and in that case the logger also uses newlines chars:

w: Writes data with the standard syntax. This is used to output Erlang terms. Atoms are printed within quotes if they contain embedded non-printable characters. Atom characters > 255 are es‐ caped unless the Unicode translation modifier (t) is used. Floats are printed accurately as the shortest, correctly rounded string.

p: Writes the data with standard syntax in the same way as ~w, but breaks terms whose printed representation is longer than one line into many lines and indents each line sensibly. Left- justification is not supported. It also tries to detect flat lists of printable characters and output these as strings.

On the other hand, the logger_journald library that I mentioned earlier generates one single line:

de juny 28 19:03:22 atenea ejabberd[33730]: API call register [{<<"user">>,<<"user1">>},{<<"host">>,<<"localhost">>},{<<"password">>,<<"asd1">>}] ({0,0,0,0,0,65535,32512,1})

[logicwonder]

Thanks @badlop. Will explore the logstash libraries. Where do I need to apply these changes in eJabberd for writing logs in standard syntax?

[badlop]

I pushed this commit to my fork repository. It works for me: https://github.com/badlop/ejabberd/commit/8c0da87012a9f72f2e869e93b733bead168febb5

I just learned about logstash, so you may need to update configuration, etc for a real production usage.

Please comment your results, and whatever improvements you make for a real usage.

[logicwonder]

Thank you @badlop I have tested the commit and found that the new line issues with info, error level messages are resolved. And everything is getting wrapped into the message field in logstash.

An issue is identified with critical error log processing. The message field is nil and the fields attribute is becoming complex. See below:

{
         "event" => {
        "original" => "{\"@timestamp\":\"2022-06-30T08:03:23.138743Z\",\"fields\":{\"severity\":\"error\",\"domain\":[\"otp\",\"sasl\"],\"error_logger\":\"\#{tag => error_report,type => crash_report}\",\"file\":\"proc_lib.erl\",\"gl\":\"<0.749.0>\",\"line\":508,\"logger_formatter\":\"\#{title => \\\"CRASH REPORT\\\"}\",\"mfa\":\"{proc_lib,crash_report,4}\",\"pid\":\"<0.842.0>\",\"report_cb\":\"fun proc_lib:report_cb/2\",\"time\":1656576203138743,\"label\":\"{proc_lib,crash}\",\"report\":[[\"{initial_call,{ejabberd_mnesia,init,['Argument__1']}}\",\"{pid,<0.842.0>}\",\"{registered_name,[]}\",\"{error_info,{exit,node_name_mismatch,\\n                  [{gen_server,init_it,6,[{file,\\\"gen_server.erl\\\"},{line,358}]},\\n                   {proc_lib,init_p_do_apply,3,\\n                             [{file,\\\"proc_lib.erl\\\"},{line,249}]}]}}\",\"{ancestors,[<0.750.0>]}\",\"{message_queue_len,0}\",\"{messages,[]}\",\"{links,[<0.750.0>]}\",\"{dictionary,[]}\",\"{trap_exit,false}\",\"{status,running}\",\"{heap_size,1598}\",\"{stack_size,27}\",\"{reductions,15008}\"],\"\"]},\"message\":null}"
    },
    "@timestamp" => 2022-06-30T08:03:23.138743Z,
        "fields" => {
                  "report" => [
            [0] [
                [ 0] "{initial_call,{ejabberd_mnesia,init,['Argument__1']}}",
                [ 1] "{pid,<0.842.0>}",
                [ 2] "{registered_name,[]}",
                [ 3] "{error_info,{exit,node_name_mismatch,\n                  [{gen_server,init_it,6,[{file,\"gen_server.erl\"},{line,358}]},\n                   {proc_lib,init_p_do_apply,3,\n                             [{file,\"proc_lib.erl\"},{line,249}]}]}}",
                [ 4] "{ancestors,[<0.750.0>]}",
                [ 5] "{message_queue_len,0}",
                [ 6] "{messages,[]}",
                [ 7] "{links,[<0.750.0>]}",
                [ 8] "{dictionary,[]}",
                [ 9] "{trap_exit,false}",
                [10] "{status,running}",
                [11] "{heap_size,1598}",
                [12] "{stack_size,27}",
                [13] "{reductions,15008}"
            ],
            [1] ""
        ],
                  "domain" => [
            [0] "otp",
            [1] "sasl"
        ],
                    "line" => 508,
               "report_cb" => "fun proc_lib:report_cb/2",
                   "label" => "{proc_lib,crash}",
                     "mfa" => "{proc_lib,crash_report,4}",
                      "gl" => "<0.749.0>",
                    "time" => 1656576203138743,
                "severity" => "error",
            "error_logger" => "\#{tag => error_report,type => crash_report}",
                     "pid" => "<0.842.0>",
                    "file" => "proc_lib.erl",
        "logger_formatter" => "\#{title => \"CRASH REPORT\"}"
    },
      "@version" => "1",
          "type" => "default_log_type",
          "host" => {
        "ip" => "127.0.0.1"
    },
       "message" => nil
}

[badlop]

Apparently this was an error generated by Erlang/OTP's SASL application. I could not reproduce that case. If anybody has a clue to reproduce that problem, please give some instructions.