Message correlation, everything needs an "@"? And a grep problem.
Hello list, After playing with correlation for a while, here are a few remarks on it's workings. I have played with syslog-ng 3.2.2, built from source on an Ubuntu 10.04 machine. For some reason, the "@1", "@2"... etcetera specifiers needed to be all over the place to be able to see any variable at all. For example, the rule below describes the last message of a Postfix log trail. Note that even the context-id is specified as "${queueid}@1". All other references also have an "@" sign. Without the @, the variables seem just empty. <rule id='X' context-id="${queueid}@1" context-scope="host" provider="openoffice" class="maildelivery"> <patterns> <pattern>@ESTRING:queueid: @removed</pattern> </patterns> <actions> <action> <message> <values> <value name="MESSAGE">${queueid}@1 mail to=<${toaddress}@2> from=<${pffrom}@3> connection from=${pfremotehost}@5[${pfremoteip}@5] msgid=<${msgid}@4> orig_to=<${origto}@2> delay=${deliverystatus}@2</value> </values> </message> </action> </actions> </rule> Is this how it's meant to be? Then, when trying to use the "grep" template function in this message, I can't seem to find out how it works. Using the exact example from the documentation, $(grep ("${username}" == "root") ${auth_method}), I only get an error: Error parsing filter expression, syntax error, unexpected $undefined in <string> at line 1, column 3: (${ ^ Trying to alter the message, using "$something" == "value", doesn't seem to have an effect, i.e. I can't get "grep" to find any values. In fact, I'm not even sure if I can use the names from the (E/Q)STRING parsers right away, or if I need to have <value name="something"> tags before I can grep for them. In fact, most of the time, the grep I would like to use is something like: $(grep ( "$variable" != "" ) "$variable"). But whatever I try, no results from grep. Could anyone please clarify? Best regards, Valentijn
Hi, On Fri, 2011-02-11 at 16:48 +0100, Valentijn Sessink wrote:
Hello list,
After playing with correlation for a while, here are a few remarks on it's workings. I have played with syslog-ng 3.2.2, built from source on an Ubuntu 10.04 machine.
For some reason, the "@1", "@2"... etcetera specifiers needed to be all over the place to be able to see any variable at all. For example, the rule below describes the last message of a Postfix log trail. Note that even the context-id is specified as "${queueid}@1". All other references also have an "@" sign. Without the @, the variables seem just empty.
<rule id='X' context-id="${queueid}@1" context-scope="host" provider="openoffice" class="maildelivery"> <patterns> <pattern>@ESTRING:queueid: @removed</pattern> </patterns> <actions> <action> <message> <values> <value name="MESSAGE">${queueid}@1 mail to=<${toaddress}@2> from=<${pffrom}@3> connection from=${pfremotehost}@5[${pfremoteip}@5] msgid=<${msgid}@4> orig_to=<${origto}@2> delay=${deliverystatus}@2</value> </values> </message> </action> </actions> </rule>
Is this how it's meant to be?
hmm.. no, @1 should be the one before the current message. I've just tried to reproduce this with 3.3 but it works fine. ... seems to be work OK in 3.2 too. how did you reproduce this exactly?
Then, when trying to use the "grep" template function in this message, I can't seem to find out how it works. Using the exact example from the documentation, $(grep ("${username}" == "root") ${auth_method}), I only get an error: Error parsing filter expression, syntax error, unexpected $undefined in <string> at line 1, column 3:
(${ ^
The error message seems to indicate that the quotes are missing. Let me check this too. Yes, that's the problem. hmm.. The XML shouldn't do this, as this is a text node, not an attribute node and there '"' doesn't matter. I'll have to dig deeper.
Trying to alter the message, using "$something" == "value", doesn't seem to have an effect, i.e. I can't get "grep" to find any values. In fact, I'm not even sure if I can use the names from the (E/Q)STRING parsers right away, or if I need to have <value name="something"> tags before I can grep for them.
grep is applied to the context, and the current message is part of the context. if you want to grep for name-value pairs of the current message then yes, the values need come before the grep.
In fact, most of the time, the grep I would like to use is something like: $(grep ( "$variable" != "" ) "$variable"). But whatever I try, no results from grep.
Could anyone please clarify?
-- Bazsi
Op 20-02-11 14:43, Balazs Scheidler schreef:
Is this how it's meant to be? hmm.. no, @1 should be the one before the current message. I've just tried to reproduce this with 3.3 but it works fine.
Could it have something to do with my context-scope="host"?
... seems to be work OK in 3.2 too. how did you reproduce this exactly?
Please find attached the postfix-maildelivery pattern that I have been experimenting with. Trying to match the "queuid" within messages only worked when using "@1" - which I found rather strange. Oh, for the record: syslog-ng 3.2.2 Installer-Version: 3.2.2 Revision: ssh+git://bazsi@git.balabit//var/scm/git/syslog-ng/syslog-ng-ose--mainline--3.2#master#1d3f396485eb47b1ff6aa18ac4f1c4cd51c0ea4c Compile-Date: Feb 9 2011 13:14:58 Enable-Threads: on Enable-Debug: off Enable-GProf: off Enable-Memtrace: off Enable-Sun-STREAMS: off Enable-IPv6: on Enable-Spoof-Source: on Enable-TCP-Wrapper: off Enable-SSL: on Enable-SQL: on Enable-Linux-Caps: off Enable-Pcre: off Enable-Pacct: off Please note that the attached pattern is work (once) in progress. Anyone who would install and use this on a live machine is an idiot just like me ;) To begin with, the "program" pattern on top of the file is missing, which is not very convenient for a live server :) Development stalled when the "grep" function wouldn't work; because the pattern works for really, really simple messages but it fails completely for messages with multiple recipients (and possibly other fail factors). Trying to have "grep" output multiple values for one variable didn't work. If you know how to do that, please tell me.
Yes, that's the problem. hmm.. The XML shouldn't do this, as this is a text node, not an attribute node and there '"' doesn't matter. I'll have to dig deeper.
OK, so I gather: grep is not working right now? Best regards, Valentijn
On Sun, 2011-02-20 at 17:18 +0100, Valentijn Sessink wrote:
Op 20-02-11 14:43, Balazs Scheidler schreef:
Is this how it's meant to be? hmm.. no, @1 should be the one before the current message. I've just tried to reproduce this with 3.3 but it works fine.
Could it have something to do with my context-scope="host"?
... seems to be work OK in 3.2 too. how did you reproduce this exactly?
Please find attached the postfix-maildelivery pattern that I have been experimenting with. Trying to match the "queuid" within messages only worked when using "@1" - which I found rather strange.
Oh, for the record: syslog-ng 3.2.2 Installer-Version: 3.2.2 Revision: ssh+git://bazsi@git.balabit//var/scm/git/syslog-ng/syslog-ng-ose--mainline--3.2#master#1d3f396485eb47b1ff6aa18ac4f1c4cd51c0ea4c Compile-Date: Feb 9 2011 13:14:58 Enable-Threads: on Enable-Debug: off Enable-GProf: off Enable-Memtrace: off Enable-Sun-STREAMS: off Enable-IPv6: on Enable-Spoof-Source: on Enable-TCP-Wrapper: off Enable-SSL: on Enable-SQL: on Enable-Linux-Caps: off Enable-Pcre: off Enable-Pacct: off
Please note that the attached pattern is work (once) in progress. Anyone who would install and use this on a live machine is an idiot just like me ;)
To begin with, the "program" pattern on top of the file is missing, which is not very convenient for a live server :)
Development stalled when the "grep" function wouldn't work; because the pattern works for really, really simple messages but it fails completely for messages with multiple recipients (and possibly other fail factors). Trying to have "grep" output multiple values for one variable didn't work. If you know how to do that, please tell me.
Yes, that's the problem. hmm.. The XML shouldn't do this, as this is a text node, not an attribute node and there '"' doesn't matter. I'll have to dig deeper.
OK, so I gather: grep is not working right now?
Here's a fix for $(grep) (and also $(if)), just pushed so it's hot :) commit 045be28278fa28cb6be8e8e8063a157efaef40ef Author: Balazs Scheidler <bazsi@balabit.hu> Date: Tue Mar 1 21:19:19 2011 +0100 templates: added syntactic sugar for using filter expressions in template functions $(grep) and $(if) take a filter expression as argument, however such expressions may require quoted strings. The default behaviour of the parser in this case was to remove quotes. This is fixed by not caring about quotes within parenthesises, so $(grep) beomes usable with this syntax: $(grep ('$FACILITY' == 'level4') $MSG) This works since the parentheses around the filter expression is nicely processed by the filter anyway, and the template function arg parser ignores quotes in this case. Reported-By: Valentijn Sessink <valentyn@blub.net> Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> -- Bazsi
On Sun, 2011-02-20 at 14:43 +0100, Balazs Scheidler wrote:
Hi,
On Fri, 2011-02-11 at 16:48 +0100, Valentijn Sessink wrote:
Hello list,
After playing with correlation for a while, here are a few remarks on it's workings. I have played with syslog-ng 3.2.2, built from source on an Ubuntu 10.04 machine.
For some reason, the "@1", "@2"... etcetera specifiers needed to be all over the place to be able to see any variable at all. For example, the rule below describes the last message of a Postfix log trail. Note that even the context-id is specified as "${queueid}@1". All other references also have an "@" sign. Without the @, the variables seem just empty.
<rule id='X' context-id="${queueid}@1" context-scope="host" provider="openoffice" class="maildelivery"> <patterns> <pattern>@ESTRING:queueid: @removed</pattern> </patterns> <actions> <action> <message> <values> <value name="MESSAGE">${queueid}@1 mail to=<${toaddress}@2> from=<${pffrom}@3> connection from=${pfremotehost}@5[${pfremoteip}@5] msgid=<${msgid}@4> orig_to=<${origto}@2> delay=${deliverystatus}@2</value> </values> </message> </action> </actions> </rule>
Is this how it's meant to be?
hmm.. no, @1 should be the one before the current message. I've just tried to reproduce this with 3.3 but it works fine.
... seems to be work OK in 3.2 too. how did you reproduce this exactly?
I looked into this problem, and now I know the root cause. In case of the main body of the rule, @1 is the predecessor message and @0 is the current one. However within <actions>, the message being created is also added to the context temporarily, e.g. the numbers are shifted up I don't remember my original intention, it was probably just for symmetry's sake, by this patch: $ git show 058e8499 commit 058e8499e2d2513b1da7fccf694b60f4b25dfbaf Author: Balazs Scheidler <bazsi@balabit.hu> Date: Mon Oct 11 14:50:10 2010 +0200 patterndb: temporarily add the message being generated to the context diff --git a/modules/dbparser/patterndb.c b/modules/dbparser/patterndb.c index 14e511b..b4c05a4 100644 --- a/modules/dbparser/patterndb.c +++ b/modules/dbparser/patterndb.c @@ -521,7 +521,9 @@ pdb_rule_run_actions(PDBRule *self, gint trigger, PatternDB *db, PDBContext *con g_assert_not_reached(); break; } + g_ptr_array_add(context->messages, genmsg); pdb_message_apply(&action->content.message, context, genmsg, buffer); + g_ptr_array_remove_index_fast(context->messages, context->messages->len - 1); emit(genmsg, TRUE, emit_data); break; default: This behaviour makes it possible to reference name-value pairs of the _current_ message (e.g. the one being generated), but that's usually empty (except for the default fields HOST, PROGRAM & PID depending on how the context was filled). Documentation wise, this is bad behaviour, as the documentation contains the one without '@1' values, but there are two releases in the 3.2 branch which behave as you have found out. I'd say that not that many people are probably using this feature right now, so I'd go for reverting that patch. Are there any other opinions? -- Bazsi
Op 01-03-11 20:50, Balazs Scheidler schreef: [...]
I'd say that not that many people are probably using this feature right now, so I'd go for reverting that patch.
Or update the documentation :) My feeling is that the "@1" adds extra complexity now - see the context-id example with "${queueid}@1". Given how new this correlating thing is, and the (relative) lack of example correlating patterns there is - no, I don't think many people are using it... yet ;-) Valentijn
On Tue, 2011-03-01 at 21:05 +0100, Valentijn Sessink wrote:
Op 01-03-11 20:50, Balazs Scheidler schreef: [...]
I'd say that not that many people are probably using this feature right now, so I'd go for reverting that patch.
Or update the documentation :)
My feeling is that the "@1" adds extra complexity now - see the context-id example with "${queueid}@1".
Given how new this correlating thing is, and the (relative) lack of example correlating patterns there is - no, I don't think many people are using it... yet ;-)
Hmm.. I didn't even notice the context-id part, that's different from the problem I realised. the context-id is expanded _before_ even identifying the context, so that shouldn't work that way. Let me check. -- Bazsi
On Tue, 2011-03-01 at 21:21 +0100, Balazs Scheidler wrote:
On Tue, 2011-03-01 at 21:05 +0100, Valentijn Sessink wrote:
Op 01-03-11 20:50, Balazs Scheidler schreef: [...]
I'd say that not that many people are probably using this feature right now, so I'd go for reverting that patch.
Or update the documentation :)
My feeling is that the "@1" adds extra complexity now - see the context-id example with "${queueid}@1".
Given how new this correlating thing is, and the (relative) lack of example correlating patterns there is - no, I don't think many people are using it... yet ;-)
Hmm.. I didn't even notice the context-id part, that's different from the problem I realised.
the context-id is expanded _before_ even identifying the context, so that shouldn't work that way.
Let me check.
hmm. that's right, @1 at context-id expansion time is undefined and becomes the empty string: (gdb) p rule->context_id_template->template $2 = (gchar *) 0x6276a0 "foobar.${usracct.username}@1" (gdb) n 1454 pdb_state_key_setup(&key, PSK_CONTEXT, rule, msg, buffer->str); (gdb) p buffer->str $3 = (gchar *) 0x62eea0 "foobar." In contrast with: (gdb) p rule->context_id_template->template $2 = (gchar *) 0x6276a0 "foobar.${usracct.username}" (gdb) n 1454 pdb_state_key_setup(&key, PSK_CONTEXT, rule, msg, buffer->str); (gdb) p buffer->str $1 = (gchar *) 0x62eea0 "foobar.bazsi" -- Bazsi
Op 01-03-11 21:26, Balazs Scheidler schreef:
Hmm.. I didn't even notice the context-id part, that's different from the problem I realised.
the context-id is expanded _before_ even identifying the context, so that shouldn't work that way.
Hmm. That's not what I found. Without "@1", my postfix-correlation did not work. With @1, it did. I'm 100% sure. Could the context-scope="host" have anything to do with it? The context-id being ${queue-id} is crucial here, because this is the only way to follow a postfix mail through the various handlers. V.
On Tue, 2011-03-01 at 21:57 +0100, Valentijn Sessink wrote:
Op 01-03-11 21:26, Balazs Scheidler schreef:
Hmm.. I didn't even notice the context-id part, that's different from the problem I realised.
the context-id is expanded _before_ even identifying the context, so that shouldn't work that way.
Hmm. That's not what I found. Without "@1", my postfix-correlation did not work. With @1, it did. I'm 100% sure.
Could the context-scope="host" have anything to do with it?
Well, I'm positive that if you use @1 in there, then that value expands to nothing. It is still an ID nevertheless.
The context-id being ${queue-id} is crucial here, because this is the only way to follow a postfix mail through the various handlers.
-- Bazsi
Op 01-03-11 23:51, Balazs Scheidler schreef:
Hmm. That's not what I found. Without "@1", my postfix-correlation did not work. With @1, it did. I'm 100% sure. Well, I'm positive that if you use @1 in there, then that value expands to nothing.
I'll re-check. Now that grep() works, a postfix delivery trail pattern would be feasible, so it makes sense to try again. V.
Hello list, On 01-03-11 23:51, Balazs Scheidler wrote:
Well, I'm positive that if you use @1 in there, then that value expands to nothing. It is still an ID nevertheless.
I don't think I can get the "context-id" stuff to work with a queue-id. I tried, but apparently, the inner workings of message correlation escape me. I *thought* I almost had it working with 3.2.2, but now after a recompile from the git repository, I can't get it to work - at all. Don't worry, I'll blame myself. Please find attached my utterly broken postfix-maildelivery trial pattern. For those that are interested: it *does not work*. At all. (Maybe there's an easy fix because of blatant errors in my pattern - then please tell me so.) Best regards, Valentijn
Please find attached my utterly broken postfix-maildelivery trial pattern. For those that are interested: it *does not work*. At all.
Classic. Forgot the attachment. V.
hi, On Thu, 2011-03-03 at 14:01 +0100, Valentijn Sessink wrote:
Please find attached my utterly broken postfix-maildelivery trial pattern. For those that are interested: it *does not work*. At all.
Classic. Forgot the attachment.
I'm not sure in what way it doesn't work, but I've added some debugging features to correllation with these two patches: commit 29e889afa7c99c5c64107fcc394505babf8c84bd Author: Balazs Scheidler <bazsi@balabit.hu> Date: Thu Mar 3 17:57:16 2011 +0100 pdbtool: added internal logging options This makes it possible to enable debug/verbose messages from pdbtool to aid patterndb debug messages. Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> commit ef2f6b4791ffb4a93ef019b1b85c2f674c1f660a Author: Balazs Scheidler <bazsi@balabit.hu> Date: Thu Mar 3 17:56:29 2011 +0100 pdbtool: fixed segfault --debug-pattern in case the pattern doesn't match Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> You didn't provide a log sample, so I collected some mail logs from our mailserver, but one of the rules didn't match as my log sample was completely different from yours (probably a postfix version difference?) Then I've extracted the example log messages in your database, and constructed and artificial log file: 2011-03-03T08:05:32.52+01:00 mail postfix/qmgr: 471C2300527: to=<example@mail.example.com>, orig_to=<example@example.com>, relay=example.com[2109:9876:34ab::f1]:25, delay=0.24, delays=0.04/0.01/0.11/0.08, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 6FC19612F6) 2011-03-03T08:05:32.52+01:00 mail postfix/qmgr: 471C2300527: message-id=<201102101555.3RHHEQ8024@desktop> 2011-03-03T08:05:32.52+01:00 mail postfix/qmgr: 471C2300527: client=example.com[2109:9876:34ab::f1] 2011-03-03T08:05:32.52+01:00 mail postfix/qmgr[3986]: 471C2300527: removed this messages all match: # this requires the new debugging patches $ pdbtool match -p postfix2.pdb -f postfix2.log -d >/dev/null Trying to open module; module='syslogformat', filename='/home/bazsi/zwa/install/syslog-ng-ose-3.2/lib/syslog-ng/libsyslogformat.so' Trying to open module; module='basicfuncs', filename='/home/bazsi/zwa/install/syslog-ng-ose-3.2/lib/syslog-ng/libbasicfuncs.so' patterndb rule matches; rule_id='39289650-0787-7b4f-a52d-c047d600de3e' Correllation context lookup failure, starting a new context; rule='39289650-0787-7b4f-a52d-c047d600de3e', context='471C2300527:', context_timeout='0' patterndb rule matches; rule_id='a249fca8-3916-2444-5238-7495cb64bf76' Correllation context lookup successful; rule='a249fca8-3916-2444-5238-7495cb64bf76', context='471C2300527:', context_timeout='0', num_messages='1' patterndb rule matches; rule_id='a649fca8-3916-2444-5238-7495cb64bf76' Correllation context lookup successful; rule='a649fca8-3916-2444-5238-7495cb64bf76', context='471C2300527:', context_timeout='0', num_messages='2' patterndb rule matches; rule_id='aaaaaaaa-3946-2444-5238-7495cb64bf76' Correllation context lookup successful; rule='aaaaaaaa-3946-2444-5238-7495cb64bf76', context='471C2300527:', context_timeout='0', num_messages='3' Filter node evaluation result; filter_result='match', filter_type='CMP' The <message> action is triggered, but the values are empty: $ pdbtool match -p postfix2.pdb -f postfix2.log -d 2>/dev/null HOST=mail MESSAGE=M06 471C2300527:/471C2300527: mail to=<> from=<> connection from=[] msgid=<> orig_to=<> delay= But the root cause was that the message indexes didn't match my log sample. Anyway while doing so, I've discovered that there was another problem with $(grep), it basically _always_ operated on a single element. I remember that it actually worked better, but I probably broke it while developing further features and the unit tests didn't cover all cases properly. This patch fixes that: commit a93a4413404d2e3342641cf2be557b1e9b134279 Author: Balazs Scheidler <bazsi@balabit.hu> Date: Thu Mar 3 19:19:35 2011 +0100 templates: fixed @XX style msg_ref parsing Function invocations (e.g. $(grep)) didn't get the complete context as one extremal value for msg_ref (==0) which indicated that the user didn't specify an msg_ref was not properly used in the code. This basically meant that $(grep) only operated on a single element, which is not very usable after all. As it seems the unit test didn't cover all cases properly. This patch fixes up all cases and adds unit test coverage. Signed-off-by: Balazs Scheidler <bazsi@balabit.hu> With this the $(grep) that you embedded in the message started to work fine. I've also changed a couple of @xx references in your message template, and I got this: HOST=mail MESSAGE=M06 471C2300527:/471C2300527: mail to=<example@mail.example.com> from=<sender@mail.example.com> connection from=example.com[2109:9876:34ab::f1] msgid=<201102101555.3RHHEQ8024@desktop> orig_to=<example@example.com> 471C2300527:,471C2300527:,471C2300527:,471C2300527:,471C2300527:, delay=0.24, delays=0.04/0.01/0.11/0.08, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 6FC19612F6) Hopefully, it'll be ok now. Sorry for messing it up this badly :( I probably could have spared you a lot of time if I had my testcases done properly. But anyway, the PE team is now working on properly writing up the correllation functionality and doing automated tests for them, which are less shabby than my own, so it'll sure get some drastic improvements in the nearfuture :) -- Bazsi
Hi, On 03-03-11 19:24, Balazs Scheidler wrote:
With this the $(grep) that you embedded in the message started to work fine.
Ah. Good. I'll see if I can find some time for repairing my Postfix mail trail pattern.
I've also changed a couple of @xx references in your message template, and I got this:
HOST=mail MESSAGE=M06 471C2300527:/471C2300527: mail to=<example@mail.example.com> from=<sender@mail.example.com> connection from=example.com[2109:9876:34ab::f1] msgid=<201102101555.3RHHEQ8024@desktop> orig_to=<example@example.com> 471C2300527:,471C2300527:,471C2300527:,471C2300527:,471C2300527:, delay=0.24, delays=0.04/0.01/0.11/0.08, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 6FC19612F6)
Looks promising :)
Hopefully, it'll be ok now. Sorry for messing it up this badly :( I probably could have spared you a lot of time if I had my testcases done properly.
Yep. OTOH, you have *saved* me a lot of time because I did not have to install sshguard ;-) Valentijn
On Tue, 2011-03-01 at 21:05 +0100, Valentijn Sessink wrote:
Op 01-03-11 20:50, Balazs Scheidler schreef: [...]
I'd say that not that many people are probably using this feature right now, so I'd go for reverting that patch.
Or update the documentation :)
My feeling is that the "@1" adds extra complexity now - see the context-id example with "${queueid}@1".
Given how new this correlating thing is, and the (relative) lack of example correlating patterns there is - no, I don't think many people are using it... yet ;-)
I now realised what my original intention with this was. So I've now changed my mind and I think it should stay as it is and the documentation should be updated instead. The original intention with adding the currently generated message into the correllation state as @0 (thereby shifting away the whole context) is to make it possible to collect values into using $(grep) and then reuse those name-value pairs in another value. For example, consider a postfix correllation state, which contains a recipient address in one of its messages, but we don't know which one exactly (or which order the messages arrive). In this case we could do something like: <value name="sender">$(grep ('${.classifier.rule_id}' == 'ruleid-matching-sender-address') ${sender})</value> <value name="recipient">$(grep ('${.classifier.rule_id}' == 'ruleid-matching-recipient-address') ${recipient})</value> And then use this in our message template (the same action, just another name-value pair assignment) <value name='MESSAGE'>hey, a message was sent from ${sender} to ${recipient}</value> This is good news, since I don't have to break the currently released behaviour. :) I'm happy. Note to self: I should have written the intentions into the commit message at the minimum. -- Bazsi
participants (2)
-
Balazs Scheidler
-
Valentijn Sessink