rsyslog / liblognorm

a fast samples-based log normalization library
http://www.liblognorm.com
GNU Lesser General Public License v2.1
99 stars 64 forks source link

Unset breaks parsing and generates UTF-8 chars #243

Closed MrSam closed 7 years ago

MrSam commented 7 years ago

Log file: 2017/01/31 14:36:27 [error] 25706#0: *15921 no user/password was provided for basic authentication, client: xxx.xx.xx.xx, server: some-server, request: "HEAD / HTTP/1.1", host: "rock.some-host.com" rule: rule=:%date_year:char-to:/%/%date_month:char-to:/%/%date_day:word% %time:word% [%level:char-to:]%] %message:rest%

rsyslog:

  set $!server = $hostname;
  set $!logtype = "error";
  set $!tag = "nginx";
  set $!timestamp = $!date_year & "-" & $!date_month & "-" & $!date_day & "T" &$!time & "+00:00";
  unset $!date_year;
  unset $!date_month;
  unset $!date_day;
  unset $!time;

if i leave them i get something like: { "message": "25706#0: *15926 no user\/password was provided for basic authentication, client: xxx.xxx.xxx.xx, server: some-servercom, request: \"HEAD \/ HTTP\/1.1\", host: \"rock.the-xxxxx.com\"", "level": "error", "0�Z\u0002": "14:41:19", "�Z\u0002": "31", "��Z\u0002": "01", "": "2017", "server": "lb5", "logtype": "error", "tag": "nginx", "timestamp": "--T+00:00" }`

if i comment the unset: { "message": "25706#0: *15927 no user\/password was provided for basic authentication, client: xxx.xxx.xxx.xxx, server: some-server.com, request: \"HEAD \/ HTTP\/1.1\", host: \"rock.xxxx.com\"", "level": "error", "time": "14:42:48", "date_day": "31", "date_month": "01", "date_year": "2017", "server": "lb5", "logtype": "error", "tag": "nginx", "timestamp": "2017-01-31T14:42:48+00:00" }

MrSam commented 7 years ago

Versions used: root@lb5:/etc/rsyslog.d# dpkg -l |grep rsys ii rsyslog 8.24.0-0adiscon1trusty1 ii rsyslog-elasticsearch 8.24.0-0adiscon1trusty1 ii rsyslog-mmfields 8.24.0-0adiscon1trusty1 ii rsyslog-mmjsonparse 8.24.0-0adiscon1trusty1 ii rsyslog-mmnormalize 8.24.0-0adiscon1trusty1 root@lb5:/etc/rsyslog.d#

davidelang commented 7 years ago

On Tue, 31 Jan 2017, Sam Hermans wrote:

Log file: 2017/01/31 14:36:27 [error] 25706#0: *15921 no user/password was provided for basic authentication, client: xxx.xx.xx.xx, server: some-server, request: "HEAD / HTTP/1.1", host: "rock.some-host.com"

Config:

rule=:%date_year:char-to:/%/%date_month:char-to:/%/%date_day:word% %time:word% [%level:char-to:]%] %message:rest%
 set $!server = $hostname;
 set $!logtype = "error";
 set $!tag = "nginx";
 set $!timestamp = $!date_year & "-" & $!date_month & "-" & $!date_day & "T" &$!time & "+00:00";
 unset $!date_year;
 unset $!date_month;
 unset $!date_day;
 unset $!time;

the rule belongs in a rule file, while the set and unset belong in rsyslog.conf, they can't be in the same file.

David Lang

if i leave them i get something like: { "message": "25706#0: *15926 no user\/password was provided for basic authentication, client: xxx.xxx.xxx.xx, server: some-servercom, request: \"HEAD \/ HTTP\/1.1\", host: \"rock.the-xxxxx.com\"", "level": "error", "0???Z\u0002": "14:41:19", "???Z\u0002": "31", "??????Z\u0002": "01", "": "2017", "server": "lb5", "logtype": "error", "tag": "nginx", "timestamp": "--T+00:00" }`

if i comment the unset: { "message": "25706#0: *15927 no user\/password was provided for basic authentication, client: xxx.xxx.xxx.xxx, server: some-server.com, request: \"HEAD \/ HTTP\/1.1\", host: \"rock.xxxx.com\"", "level": "error", "time": "14:42:48", "date_day": "31", "date_month": "01", "date_year": "2017", "server": "lb5", "logtype": "error", "tag": "nginx", "timestamp": "2017-01-31T14:42:48+00:00" }

MrSam commented 7 years ago

This is the case, i was just simplifying the comment.

davidelang commented 7 years ago

On Tue, 31 Jan 2017, Sam Hermans wrote:

This is the case, i was just simplifying the comment.

Please write $! to a file before and after the unset statements so we can see exactly what is happening with a single log message

an unset that takes place after the call to mmnormalize isn't going to break the parsing (it can't, the parsing has already taken place) so there is something else going on here.

David Lang

davidelang commented 7 years ago

also, what version of liblognorm do you have? is it linked to libfastjson or json-c

janmejay commented 7 years ago

I believe we have tests that both set and unset. Its a little surprising that it wasn't caught.

Please confirm if it is json-c or libfastjson.

On Feb 1, 2017 3:44 AM, "davidelang" notifications@github.com wrote:

also, what version of liblognorm do you have? is it linked to libfastjson or json-c

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/rsyslog/liblognorm/issues/243#issuecomment-276510413, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAx6W7QOGOHJorPMwxJXffC22PFd6KAks5rX7JMgaJpZM4LyuLR .

rgerhards commented 7 years ago

In any case, this is not a liblognorm issue. If the issue persists with libfastjson, please open an issue tracker at the rsyslog project.