[syslog-ng] syslog-ng, json and handle escaping properly

[Antal Nemes (anemes)]

 Hello,

I think the simplest approach would be if you feed a properly formatted json into the source (just add {} brackets to _PRINT_DEBUG). Use json-parser to turn the input into name-value pairs. Then print everything with the format-json template function.

I simulated the json input with example-msg generator for sake of simplicity, but I think similar config could work for your source too.

@version: 3.26

log {
  source { example-msg-generator(num(1) template("{\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Check pstore partition..\"}")); };
  parser { json-parser(); };
  destination { file(/dev/stdout template("$(format-json --key category,level,message timestamp=${ISODATE})\n")); };
};

This outputs:

{"timestamp":"2020-04-24T12:37:58+02:00","message":"Check pstore partition..","level":"INFO","category":"BOOT"}

Br,
  Antal

________________________________
From: syslog-ng <syslog-ng-bounces at lists.balabit.hu> on behalf of Arthur Lambert <lambertarthur22 at gmail.com>
Sent: Tuesday, April 21, 2020 11:56
To: syslog-ng at lists.balabit.hu <syslog-ng at lists.balabit.hu>
Subject: [syslog-ng] syslog-ng, json and handle escaping properly

CAUTION: This email originated from outside of the organization. Do not follow guidance, click links, or open attachments unless you recognize the sender and know the content is safe.

Hello,

I tried to migrate from syslog to Syslog-ng. I am trying to deploy it on an embedded target
with buildroot. At the same time, I also tried to switch log format to JSON.

In my c code, I use Syslog function and init with the openlog function:
openlog("middleware", 0, LOG_LOCAL1);

I have some macro to generate the json logs:
#define _PRINT_DEBUG(M, ...) \
do { \
syslog(LOG_DEBUG, "\"category\":\"%s\",\"level\":\"DEBUG\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \
} while (0)

I define a syslog-ng conf file:

@version: 3.2X

filter f_middleware {
    facility("local1");
};

template t_json_filetemplate {
    template("{\"timestamp\":\"${ISODATE}\",${MESSAGE}\n");
};

source s_kernel {
    file("/proc/kmsg" program_override("kernel"));
};

source s_middleware {
    unix-stream("/dev/log");
};

destination d_kernel {
    file("/data/logs/kern.log");
};

destination d_middleware {
    file("/data/logs/middleware.log", template(t_json_filetemplate));
};

log {
    source(s_kernel);
    destination(d_kernel);
};

log {
    source(s_middleware);
    filter(f_middleware);
    destination(d_middleware);
};

So basically I want to redirect all my log from my code in /data/logs/middleware.log. I also want to redirect all kernel logs
in /data/logs/kern.log

I have two issues. The first one is escaping.
If I want to print a JSON file the double quote will be not escaped. My first solution was to use escape feature from Syslog-ng:
destination d_middleware {
        file("/data/logs/middleware.log", template("{\"timestamp\":\"${ISODATE}\",${MESSAGE}\n") template-escape(yes));

};

Problem is that now everything is escaped and not only the message, some example:
{"timestamp":"2020-04-21T09:24:02+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Check pstore partition..\"}
{"timestamp":"2020-04-21T09:24:02+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Start hardware watchdog daemon...\"}
{"timestamp":"2020-04-21T09:24:02+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Prepare asound configuration...\"}
{"timestamp":"2020-04-21T09:24:02+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Middleware is about to start...\"}
{"timestamp":"2020-04-21T09:24:03+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Load sdma firmware..\"}
{"timestamp":"2020-04-21T09:24:03+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Watchdog is about to start...\"}
{"timestamp":"2020-04-21T09:24:03+02:00",\"category\":\"BOOT\",\"level\":\"INFO\",\"message\":\"Start mpu watchdog..\"}

As you can see, everything is escaped because for Syslog-ng, everything is the message and not only the final part. I feel like I am completely
using Syslog-ng in the wrong way right? How can I fix that? Do I have to handle escaping by myself manually in my middleware?
Do I have to pre-process all logs manually by myself? It seems quite awful.

I have a second issue which is probably related? When I tried to print the content of a file, the last '}' is truncated. The reason seems to be related
to the presence of \n. I can reproduce the issue by just calling my PRINT_DEBUG macro as follow:

PRINT_DEBUG ("YO YO YO KO\n");
PRINT_DEBUG ("YO YO YO OK");

The result:

{"timestamp":"2020-04-21T09:24:03+02:00",\"category\":\"MPU_CORE\",\"level\":\"DEBUG\",\"message\":\"YO YO YO KO
{"timestamp":"2020-04-21T09:24:03+02:00",\"category\":\"MPU_CORE\",\"level\":\"DEBUG\",\"message\":\"YO YO YO OK\"}

My syslog version/module information :

# syslog-ng -V -s
syslog-ng 3 (3.26.1)
Config version: 3.22
Installer-Version: 3.26.1
Revision:
Compile-Date: Apr 10 2020 16:41:46
Module-Directory: /usr/lib/syslog-ng
Module-Path: /usr/lib/syslog-ng
Include-Path: /usr/share/syslog-ng/include
Available-Modules: add-contextual-data,affile,afprog,afsocket,afstomp,afuser,appmodel,azure-auth-header,basicfuncs,cef,confgen,cryptofuncs,csvparser,dbparser,disk-buffer,examples,graphite,hook-commands,ht
tp,kvformat,linux-kmsg-format,map-value-pairs,mod-python,pseudofile,snmptrapd-parser,stardate,syslogformat,system-source,tags-parser,tfgetent,timestamp,xml
Enable-Debug: off
Enable-GProf: off
Enable-Memtrace: off
Enable-IPv6: on
Enable-Spoof-Source: off
Enable-TCP-Wrapper: off
Enable-Linux-Caps: off
Enable-Systemd: off

--
- Arthur LAMBERT
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.balabit.hu/pipermail/syslog-ng/attachments/20200424/34780feb/attachment-0001.html>