On 12/15/2013 08:41 PM, David Lang wrote:
On Sun, 15 Dec 2013, Erik Steffl wrote:
changed config so now the MARK messages are sent (and received). BTW
they use kern.info facility, not sure why it's not the same as what
Rainer found in source (syslog.info).
This solves the simple test case in which I only have sender, load
balancer (ELB) and receiver. I strace both sender and receiver, see
the MARK messages and the connection is fine, i.e. I send a log
message using e.g. logger, then wait 5 min, then send another one and
it works. Without MARK the second message never arrives.
However in a more complex scenario this does not help at all. Complex
scenario looks like this (ascii arrows are flows of syslog messages):
- 6 machines -> ELB-prod -> collector-prod
- 1 machine -> ELB-test -> collector-test
- every 5 minutes: collector-test -> ELB-prod -> collector-prod
- every 5 minutes: collector-prod -> ELB-prod -> collector-prod (yes,
program on collector-prod sends message to rsyslog on collector-prod
over ELB)
that 5 minute pause cause the connection to go stale somehow which
results in periods of silence. I configured both collector-prod and
collector-test to send MARK messages (to collector-prod since that's
where they send regular messages) but I still see the periods of
silence (on both collectors). Used strace to verify that MARK messages
arrive (I guess it's possible that I confused the MARK messages from
collector-prod and collector-test, will continue investigating on that
front)
However adding cron entry to send few log messages every minute DOES
solve the problem (there is no silence anymore).
Any ideas why that would be? Is it possible that MARK messages are
being sent through different connections than other messages?
As far as I can tell the only difference between MARK messages and
the cron'd messages is that the MARK messages are generated by immark
and use kern.info facilty and the cron'd messages arrive via /dev/log
and use local0.info facility.
Any ideas why would the simpler scenario behave differently than the
complex scenario? Or why MARK messages do not solve the problem in
complex scenario while cron'd messages do?
my guess is that you have some bug in your config that is not forwarding
the mark messages in the more complex case.
There really isn't a difference as far as this problem is concerned
between cron generating the message and immark generating the message.
As you note, it's just which process does the work.
I thought so too but I am looking at strace of receiving syslog and
it is a bit strange. I definitely see the MARK messages coming through,
as well as the cron'd messages (each once a minute).
Since the messages have hostname in them I am pretty sure they are
coming from a given machine (collector-test sends them to collector-prod).
There seems to be something styrange about the MARK messages. I see
the cron'd messages sent every minute and each is one recvfrom syscall.
I also see some MARK messages like that but then I see recvfrom syscall
that has LOT of MARK messages (from recent past).
I also do not see MARK messages being sent every minute which I guess
is OK because they are only sent if there is no traffic. Then again why
are they being sent at all if there are cron'd messages sent every minute?
Here's what it looks like (added some newliones to make it slightly
more readable:
[pid 32602] 06:48:57.177317 recvfrom(149, "10 syslog 335
<6>2013-12-16T06:48:56.164906+00:00 ip-10-158-97-169 rsyslogd:
@cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:48:56.164906+00:00\"}}\n\n",
32768, MSG_DONTWAIT, NULL, NULL) = 350
[pid 32602] 06:49:03.241900 recvfrom(145, "409 syslog 389
<134>2013-12-16T06:49:01.597357+00:00 ip-10-158-97-169 logBurst[27810]:
@cee:{\"message-json\":{\"count\":\"0/1\",\"now\":\"Mon Dec 16 06:49:01
2013\"},\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"logBurst[27810]:\",\"programname\":\"logBurst\",\"priority\":\"local0.info\",\"timestamp\":\"2013-12-16T06:49:01.597357+00:00\"}}\n\n",
32768, MSG_DONTWAIT, NULL, NULL) = 405
[pid 32602] 06:50:03.187597 recvfrom(145, "410 syslog 389
<134>2013-12-16T06:50:01.793862+00:00 ip-10-158-97-169 logBurst[27813]:
@cee:{\"message-json\":{\"count\":\"0/1\",\"now\":\"Mon Dec 16 06:50:01
2013\"},\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"logBurst[27813]:\",\"programname\":\"logBurst\",\"priority\":\"local0.info\",\"timestamp\":\"2013-12-16T06:50:01.793862+00:00\"}}\n\n",
32768, MSG_DONTWAIT, NULL, NULL) = 405
[pid 32602] 06:50:59.426536 recvfrom(149, "2 syslog 335
<6>2013-12-16T06:40:55.748869+00:00 ip-10-158-97-169 rsyslogd:
@cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:40:55.748869+00:00\"}}\n\n3
syslog 335 <6>2013-12-16T06:41:55.808933+00:00 ip-10-158-97-169
rsyslogd: @cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:41:55.808933+00:00\"}}\n\n4
syslog 335 <6>2013-12-16T06:42:55.869729+00:00 ip-10-158-97-169
rsyslogd: @cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:42:55.869729+00:00\"}}\n\n5
syslog 335 <6>2013-12-16T06:43:55.895209+00:00 ip-10-158-97-169
rsyslogd: @cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:43:55.895209+00:00\"}}\n\n6
syslog 335 <6>2013-12-16T06:44:55.916881+00:00 ip-10-158-97-169
rsyslogd: @cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"programname\":\"rsyslogd\",\"priority\":\"kern.info\",\"timestamp\":\"2013-12-16T06:44:55.916881+00:00\"}}\n\n7
syslog 335 <6>2013-12-16T06:45:55.980382+00:00 ip-10-158-97-169
rsyslogd: @cee:{\"message-text\":\"-- MARK
--\",\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"rsyslogd:\",\"pro"...,
32768, MSG_DONTWAIT, NULL, NULL) = 3842
[pid 32602] 06:51:02.460475 recvfrom(145, "411 syslog 389
<134>2013-12-16T06:51:01.985229+00:00 ip-10-158-97-169 logBurst[27816]:
@cee:{\"message-json\":{\"count\":\"0/1\",\"now\":\"Mon Dec 16 06:51:01
2013\"},\"yummlyLogOrigin\":{\"supportLevel\":\"prod\",\"system\":\"LOGS\",\"cluster\":\"prod\",\"role\":\"collectorErik\",\"host\":\"ip-10-158-97-169\",\"tag\":\"logBurst[27816]:\",\"programname\":\"logBurst\",\"priority\":\"local0.info\",\"timestamp\":\"2013-12-16T06:51:01.985229+00:00\"}}\n\n",
32768, MSG_DONTWAIT, NULL, NULL) = 405
06:48:57.177317 MARK
06:49:03.241900 logBurst (1 cron'd message)
06:50:03.187597 logBurst
06:50:59.426536 MARK timestamped 06:40:55.748869 etc.
06:51:02.460475 logBurst
The same group of MARK messages was sent at least once before (or at
least group with same first message).
Why would the MARK message be resend in a group (or send for the
first time maybe, didn't get that far yet).
Seems like one of two scenarios happens:
- MARK messages are for some reason grouped together, so they end up
not being sent over the wire every minute (and they don't prevent the
connection from going bad).
- MARK messages are sent but relp confirmation is not sent so they
keep being re-send. Note that cron'd message aree not resent so there is
nothing wrong with connection and nothing preventing relp confirmations
to be sent back.
Could this have anything to do with RELP window, i.e. how many
messages are sent before relp confirmation is sent?
erik
David Lang
thanks!
erik
On 12/12/2013 02:39 PM, David Lang wrote:
On Thu, 12 Dec 2013, Erik Steffl wrote:
I will try to test librelp (with keepalive) but I need some
workaround in the meantime (sort of right now).
Already tested that cron-ing logger once per minute keeps the
connection alive so that's my backup workaround.
immark would be better cause then I only need to install rsyslog
config (easier deployment) plus it would be more efficient, do you
think that what David suggested is the best option?
if I understood David's comment something like this is what I am
looking for:
if
prifilt("local0.*") or
prifilt("local1.*") or
prifilt("local2.*") or
prifilt("local3.*") or
prifilt("local4.*") or
prifilt("local5.*") or
prifilt("local6.*") or
prifilt("local7.*") or
( prifilt("syslog.info") and ... message is --MARK--)
pretty much, I would do $msg == '--MARK--' as the second test
David Lang
then {
action(type="mmjsonparse")
if $parsesuccess == "OK" then {
action(
type="omrelp"
target="someHost"
port="5140"
template="json"
# see http://www.rsyslog.com/doc/node32.html
# disk used if forwarding blocked
queue.filename="json"
queue.maxdiskspace="75161927680" # 70GB (valuable data)
action.writeAllMarkMessages="on"
)
} else {
...
}
reasonable? Can be improved?
thanks!
erik
On 12/12/2013 12:44 PM, Rainer Gerhards wrote:
On Thu, Dec 12, 2013 at 9:17 PM, David Lang <[email protected]> wrote:
On Thu, 12 Dec 2013, Erik Steffl wrote:
On 12/12/2013 08:29 AM, David Lang wrote:
what facility and severity do the immark messages show up as?
immark just generates messages, normal filtering rules determine
where
theya re sent, and the transport used (in this case RELP) has no
effect
on if they are sent or not, it's all in the filters.
thanks, that makes my question a lot more specific. How do I
configure
immark to use a specific facility?
I don't think you do. I think they are using the syslog or kernel
facility, but I'd have to setup a quick test to check. I'll try to
do it
tonight if I can, but since you are seeing the messages locally, log
with
RSYSLOG_DebugFormat for a couple of minutes and look at what they are
logged as.
its syslog.=info:
http://git.adiscon.com/?p=rsyslog.git;a=blob;f=plugins/immark/immark.c;h=0e946c0b92d555174b38de42dd236ac4432b98e7;hb=HEAD#l196
All I found when searching is this:
$ModLoad immark.so
$MarkMessagePeriod 60
which is what I have in my config.
Given that I see the --MARK-- messages in /var/log/syslog and
/var/log/kern.log I guess they are going to kern facility. Given
the config
below I need to use e.g. local0 facility.
no, you need to change your filtering config to send these messages,
not
try to change the messages to match your current config.
you actually can't. I considered mark a legacy feature and have not
enhanced it since 8 yrs.
Keepalive is the better option. librelp is not yet build due to the
current
workload. The code actually right now is at github only, as I have
some
problems with the Adiscon repo. Easy to clone from here
https://github.com/rgerhards/librelp
messages have the facility that they have, you don't change the
facility
any more than you re-write the message to say something different.
actually, in this case a config option would make sense. But again, I
thought this is just legacy...
Rainer
David Lang
Unfortunately can't find anything related to --MARK-- and
facilities (or
anything else other than the two settings above).
Any ideas/pointers? Or if not possible to configure immark can I
catch
the --MARK-- message and change its facility? Or catch the --MARK--
message
and have action that uses omrelp and same target (would that use
same TCP
connection)?
Thanks!
erik
David Lang
On Thu, 12 Dec 2013, Erik Steffl wrote:
Date: Thu, 12 Dec 2013 02:30:52 -0800
From: Erik Steffl <[email protected]>
Reply-To: rsyslog-users <[email protected]>
To: rsyslog-users <[email protected]>
Subject: [rsyslog] immark - how to use with action(...)
How would I use immark to send mark messages for defined
actions that
use omrelp?
I have tried something like this:
$ModLoad immark.so
$MarkMessagePeriod 60
if(..)
if
prifilt("local0.*") or
prifilt("local1.*") or
prifilt("local2.*") or
prifilt("local3.*") or
prifilt("local4.*") or
prifilt("local5.*") or
prifilt("local6.*") or
prifilt("local7.*")
then {
action(type="mmjsonparse")
if $parsesuccess == "OK" then {
action(
type="omrelp"
target="someHost"
port="5140"
template="json"
# see http://www.rsyslog.com/doc/node32.html
# disk used if forwarding blocked
queue.filename="json"
queue.maxdiskspace="75161927680" # 70GB (valuable data)
action.writeAllMarkMessages="on"
)
} else {
...
}
I see --MARK-- messages in /var/log/syslog and
/var/log/kern.log but
they are not send by omrelp action (the action works fine, normal
messages are going through).
Verified where the --MARK-- messages are going using strace so
pretty
sure they are only going to those two local files, nothing goes
over
RELP. Also checked on the receiving side of RELP, no incoming
messages
have --MARK-- in them. And the connection goes down which is also
very
strong indicator that there are no --MARK-- messages.
How do I configure it so that the --MARK-- messages are send over
RELP
protocol to someHost (over same TCP connection that the given
action
uses, it's for purpose to keep alive the connection since RELP
does
not support KeepAlive (yet, Rainer just added it to master,
thanks!))
This is on Ubuntu 13.10 using rsyslog 7.5.6, librelp 1.2.0 from
adiscon repo.
Thanks!
erik
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT
POST
if you DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad
of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if
you
DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad
of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST
if you
DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad
of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if
you
DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT
POST if you DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST
if you DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad
of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you
DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a
myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST
if you DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad
of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you
DON'T LIKE THAT.
_______________________________________________
rsyslog mailing list
http://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE
THAT.
