Re: [syslog-ng] syslog-ng, json and handle escaping properly
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")); }; };
Ok so first I update the syslog-ng config file with your modification diff --git a/board/xxx/xxx/rootfs/etc/syslog-ng.conf b/board/xxx/xxx/rootfs/etc/syslog-ng.conf index c28ea5e59d..6b93ce24b8 100644 --- a/board/xxx/xxx/rootfs/etc/syslog-ng.conf +++ b/board/xxxx/xxx/rootfs/etc/syslog-ng.conf @@ -4,10 +4,6 @@ filter f_middleware { facility("local1"); }; -template t_json_filetemplate { - template("{\"timestamp\":\"${ISODATE}\",${MESSAGE}\n"); -}; source s_kernel { file("/proc/kmsg" program_override("kernel")); }; @@ -21,7 +17,8 @@ destination d_kernel { }; destination d_middleware { - file("/data/logs/middleware.log", template(t_json_filetemplate)); + file(/data/logs/middleware.log template("$(format-json --key category,level,message timestamp=${ISODATE})\n"));; + }; log { @@ -31,6 +28,7 @@ log { log { source(s_middleware); + parser { json-parser(); }; filter(f_middleware); destination(d_middleware); }; I also add the '{' in my macro log diff --git a/log/log_private.h b/log/log_private.h index b1e2dd31..09e875e1 100644 --- a/log/log_private.h +++ b/log/log_private.h @@ -18,7 +18,7 @@ #define _PRINT_DEBUG(M, ...) \ do { \ - syslog(LOG_DEBUG, "\"category\":\"%s\",\"level\":\"DEBUG\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ + syslog(LOG_DEBUG, "{\"category\":\"%s\",\"level\":\"DEBUG\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ } while (0) #else @@ -28,32 +28,32 @@ #define _PRINT_INF_GOTO(M, ...) \ do { \ - syslog(LOG_DEBUG, "\"category\":\"%s\",\"level\":\"INFO\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ + syslog(LOG_DEBUG, "{\"category\":\"%s\",\"level\":\"INFO\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ errno = 0; \ goto error; \ (...) #endif /* !LOG_PRIVATE_H_ */ So basically I suppose that your modification allows to syslog-ng to understand by itself that there is an extra pair key/value in my format and that I am using JSON format. So let's do some test now... int main (void) { PRINT_DEBUG ("Test simple."); PRINT_DEBUG ("\nTest with return line\n."); PRINT_DEBUG ("Test with json inside message : {\"key\" : \"%d\", \"key2\" : \"%d\"} ", 42, 21); PRINT_DEBUG ("Test simple2."); PRINT_DEBUG ("Begin. Program name : %s", argv[0]); (...) } Result : # cat /data/logs/middleware.log {"timestamp":"2020-04-24T15:36:28+02:00","message":"Test simple.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Test simple2.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Begin. Program name : nano_core","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Board config : nano_proto1","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Initialize GPIO..","level":"INFO","category":"GPIO_MANAGER"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Synchronize dictionnary with current rootfs content","level":"INFO","category":"AUDIO_MANAGER"} As you can see, the line with \n and the JSON debug output is not in the final log. It was not in a good format for the JSON syslog-ng parser. How can I fix that? Now that syslog-ng is able to understand that there is a category, a level, a message in my JSON. I cannot just ask for syslog-ng to use the escape template only on the column with message key before sending the message to the parser? I am able to fix the \n issue by using unix-dgram instead of unix-stream but without really understand why. New result after using unix-dgram : {"timestamp":"2020-04-24T15:58:09+02:00","message":"Test simple.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"\nTest with return line\n.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"Test simple2.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"Begin. Program name : nano_core","level":"DEBUG","category":"MPU_CORE"}
Hello, In case of stream, syslog-ng needs to detect the end of the message. By default it looks for newline or nullbyte as separator. In your case, on the source side, syslog-ng split your sigle _PRINT_DEBUG message in two, resulting two json fragments, non of them can be parsed by json parser. You can override this if you enable multi line mode on the source. But that means you need to match the multi line logic you specified in the source with your generator code. Look for multi-line-mode, multi-line-prefix, multi-line-suffix, multi-line-garbage in the admin guide: https://www.syslog-ng.com/technical-documents/doc/syslog-ng-open-source-edit... An alternative would be if you escape the newlines, and restore them in syslog-ng. For example, there is an url-decode template function in syslog-ng that could be used for this. There is no such problem with dgram. With dgram, one dgram->one message. Br, Antal ________________________________ From: syslog-ng <syslog-ng-bounces@lists.balabit.hu> on behalf of Arthur Lambert <lambertarthur22@gmail.com> Sent: Friday, April 24, 2020 18:00 To: syslog-ng@lists.balabit.hu <syslog-ng@lists.balabit.hu> Subject: Re: [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.
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")); }; };
Ok so first I update the syslog-ng config file with your modification diff --git a/board/xxx/xxx/rootfs/etc/syslog-ng.conf b/board/xxx/xxx/rootfs/etc/syslog-ng.conf index c28ea5e59d..6b93ce24b8 100644 --- a/board/xxx/xxx/rootfs/etc/syslog-ng.conf +++ b/board/xxxx/xxx/rootfs/etc/syslog-ng.conf @@ -4,10 +4,6 @@ filter f_middleware { facility("local1"); }; -template t_json_filetemplate { - template("{\"timestamp\":\"${ISODATE}\",${MESSAGE}\n"); -}; source s_kernel { file("/proc/kmsg" program_override("kernel")); }; @@ -21,7 +17,8 @@ destination d_kernel { }; destination d_middleware { - file("/data/logs/middleware.log", template(t_json_filetemplate)); + file(/data/logs/middleware.log template("$(format-json --key category,level,message timestamp=${ISODATE})\n"));; + }; log { @@ -31,6 +28,7 @@ log { log { source(s_middleware); + parser { json-parser(); }; filter(f_middleware); destination(d_middleware); }; I also add the '{' in my macro log diff --git a/log/log_private.h b/log/log_private.h index b1e2dd31..09e875e1 100644 --- a/log/log_private.h +++ b/log/log_private.h @@ -18,7 +18,7 @@ #define _PRINT_DEBUG(M, ...) \ do { \ - syslog(LOG_DEBUG, "\"category\":\"%s\",\"level\":\"DEBUG\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ + syslog(LOG_DEBUG, "{\"category\":\"%s\",\"level\":\"DEBUG\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ } while (0) #else @@ -28,32 +28,32 @@ #define _PRINT_INF_GOTO(M, ...) \ do { \ - syslog(LOG_DEBUG, "\"category\":\"%s\",\"level\":\"INFO\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ + syslog(LOG_DEBUG, "{\"category\":\"%s\",\"level\":\"INFO\",\"message\":\"" M "%s\"}\n", __DIR__, __VA_ARGS__); \ errno = 0; \ goto error; \ (...) #endif /* !LOG_PRIVATE_H_ */ So basically I suppose that your modification allows to syslog-ng to understand by itself that there is an extra pair key/value in my format and that I am using JSON format. So let's do some test now... int main (void) { PRINT_DEBUG ("Test simple."); PRINT_DEBUG ("\nTest with return line\n."); PRINT_DEBUG ("Test with json inside message : {\"key\" : \"%d\", \"key2\" : \"%d\"} ", 42, 21); PRINT_DEBUG ("Test simple2."); PRINT_DEBUG ("Begin. Program name : %s", argv[0]); (...) } Result : # cat /data/logs/middleware.log {"timestamp":"2020-04-24T15:36:28+02:00","message":"Test simple.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Test simple2.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Begin. Program name : nano_core","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Board config : nano_proto1","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Initialize GPIO..","level":"INFO","category":"GPIO_MANAGER"} {"timestamp":"2020-04-24T15:36:28+02:00","message":"Synchronize dictionnary with current rootfs content","level":"INFO","category":"AUDIO_MANAGER"} As you can see, the line with \n and the JSON debug output is not in the final log. It was not in a good format for the JSON syslog-ng parser. How can I fix that? Now that syslog-ng is able to understand that there is a category, a level, a message in my JSON. I cannot just ask for syslog-ng to use the escape template only on the column with message key before sending the message to the parser? I am able to fix the \n issue by using unix-dgram instead of unix-stream but without really understand why. New result after using unix-dgram : {"timestamp":"2020-04-24T15:58:09+02:00","message":"Test simple.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"\nTest with return line\n.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"Test simple2.","level":"DEBUG","category":"MPU_CORE"} {"timestamp":"2020-04-24T15:58:09+02:00","message":"Begin. Program name : nano_core","level":"DEBUG","category":"MPU_CORE"}
participants (2)
-
Antal Nemes (anemes)
-
Arthur Lambert