[syslog-ng] syslog-ng is skipping syslog events with no PRI

Mon Mar 26 10:25:21 UTC 2018

Hi Asif!

There seems to be no problem with the log structure from the filter point
of view.
I have checked it and the match() filter matched the log message.

I would recommend to debug it, e.g. in a separate environment.

Regards,
Gabor

On Fri, Mar 23, 2018 at 3:19 PM, Asif Iqbal <vadud3 at gmail.com> wrote:

>
>
> On Tue, Mar 20, 2018 at 7:21 AM, Nagy, Gábor <gabor.nagy at balabit.com>
> wrote:
>
>> Hi Asif!
>>
>> I think the problem with the first message comes from the message
>> structure and the filter statement.
>> Its structure does not conform to either syslog RFC standards (RFC3164 or
>> RFC5424).
>> Syslog-ng still tries to parse the log message by its internal heuristics
>> and the "alarmLog" text is parsed as the 'program' field.
>> You can debug syslog-ng parsing with the format-json template in the
>> destination:
>>         `template("$(format-json -s syslog-proto)\n")`
>>
>> The output for this was:
>> {"PROGRAM":"alarmLog,","PRIORITY":"notice","MESSAGE":"applianceName=Branch-UC1,
>> tenantName=DEMO-CORP, alarmType=sla-not-met, alarmKey=INTERNET,
>> generateTime=1521503387, applianceId=1, vsnId=0, tenantId=2,
>> alarmCause=datapathState, alarmClearable=yes, alarmClass=cleared,
>> alarmKind=symptom, alarmEventType=equipmentAlarm, alarmSeverity=cleared,
>> alarmOwner=tenant, alarmSeqNo=1568, alarmText=delay:9 msec,
>> siteName=Branch-UC1","HOST":"+0000","FACILITY":"user","DATE":"Mar 13
>> 23:49:48"}
>>
>>
> The issue came back after the client OS upgrade. Logs are coming in like
> this and filter f_versa { match("alarmLog"); }; does not seem to catching
> it.
>
> 12:53:46.579473 IP 192.168.1.100.58708 > 192.168.100.1.514: [|syslog]
> E..... at .>......u.....T......2018-03-23T12:53:46+0000 alarmLog,
> applianceName=MCCOLLISTER-NEWARK-7091, tenantName=MCCOLLISTER,
> alarmType=nexthop-down, alarmKey=209.36.106.241|10,
> generateTime=1521838473, applianceId=1, vsnId=0, tenantId=2,
> alarmCause=causeOther, alarmClearable=yes, alarmClass=cleared,
> alarmKind=symptom, alarmEventType=equipmentAlarm, alarmSeverity=cleared,
> alarmOwner=tenant, alarmSeqNo=41, alarmText="Nexthop
> 209.36.106.241/INTERNET-Transport-VR is up.", siteName=
> e=
>
> -VR) is up",
>
> I could not turn on debug, since I am receiving log from 1000s of routers
> as well and logs coming so fast to catch this issue.
>
> Appreciate your help!
>
>
> The filter statement uses the `match()` filter which works on both the
>> header and message part of the log message and thus would match for the
>> first log message if the `value("MESSAGE")` part would not be there.
>> With that you restricted the filter to match only on the message part.
>> If you remove the value("MESSAGE") from the filter statement it will work.
>>
>> Regards,
>> Gabor
>>
>>
>> On Tue, Mar 20, 2018 at 1:52 AM, Asif Iqbal <vadud3 at gmail.com> wrote:
>>
>>> syslog-ng is *NOT* writing syslog like this to a file which has no <
>>> *PRI*>
>>>
>>> 23:49:48.306587 IP 192.168.1.100.39567 > 192.168.100.100.514: [|syslog]
>>> E..... at .>..U...g..........T.2018-03-19T23:49:48+0000 alarmLog,
>>> applianceName=Branch-UC1, tenantName=DEMO-CORP, alarmType=sla-not-met,
>>> alarmKey=INTERNET, generateTime=1521503387, applianceId=1, vsnId=0,
>>> tenantId=2, alarmCause=datapathState, alarmClearable=yes,
>>> alarmClass=cleared, alarmKind=symptom, alarmEventType=equipmentAlarm,
>>> alarmSeverity=cleared, alarmOwner=tenant, alarmSeqNo=1568,
>>> alarmText="delay:9 msec", siteName=Branch-UC1
>>> ................
>>>
>>>
>>> syslog-ng is writing syslog like this to a file *OK *
>>>
>>> 23:50:26.930023 IP 192.168.1.100.55078 > 192.168.100.100.514: SYSLOG
>>> mail.info, length: 76
>>> E..h.B at .>......g.....&...Tt.<22>Mar 19 23:50:26 SVL-remotehost-02 root:
>>> this is third test alarmLog................
>>>
>>>
>>> Here is my syslog-ng config
>>>     source s_udp { udp(ip(0.0.0.0) port(514)); };
>>>     destination d_alarm { file("/var/log/alarms.log"); };
>>>     filter f_alarm { match("alarmLog" value("MESSAGE")); };
>>>     log { source(s_udp); filter(f_alarm); destination(d_alarm); };
>>>
>>> I am using syslog-ng version 3.5.6 on centos 7
>>>
>>> Any idea why syslog-ng is writing the first log event into a file?
>>>
>>> Appreciate any help!
>>>
>>>
>>> --
>>> Asif Iqbal
>>> PGP Key: 0xE62693C5 KeyServer: pgp.mit.edu
>>> A: Because it messes up the order in which people normally read text.
>>> Q: Why is top-posting such a bad thing?
>>>
>>>
>>> ____________________________________________________________
>>> __________________
>>> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
>>> Documentation: http://www.balabit.com/support
>>> /documentation/?product=syslog-ng
>>> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>>>
>>>
>>>
>>
>> ____________________________________________________________
>> __________________
>> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
>> Documentation: http://www.balabit.com/support
>> /documentation/?product=syslog-ng
>> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>>
>>
>>
>
>
> --
> Asif Iqbal
> PGP Key: 0xE62693C5 KeyServer: pgp.mit.edu
> A: Because it messes up the order in which people normally read text.
> Q: Why is top-posting such a bad thing?
>
>
> ____________________________________________________________
> __________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation: http://www.balabit.com/support/documentation/?
> product=syslog-ng
> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.balabit.hu/pipermail/syslog-ng/attachments/20180326/fa0f7100/attachment-0001.html>