Re: [rsyslog] imfile not sending logs to central rsyslog server

David Lang Thu, 10 Jul 2014 10:46:41 -0700

I would suggest that you have rsyslog write everything locally so that youeliminate the complexity of sending things remotely.

When you are debugging like this, it's really handy to have a single file withall the logs in it.


David Lang

On Thu, 10 Jul 2014, Xavier Fustero wrote:

Date: Thu, 10 Jul 2014 19:16:01 +0200
From: Xavier Fustero <[email protected]>
Reply-To: rsyslog-users <[email protected]>
To: rsyslog-users <[email protected]>
Subject: Re: [rsyslog] imfile not sending logs to central rsyslog server

Hi David,

the full story is a Cassandra logging through log4j. I configured log4j on
this way:

# Rolling log file
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.maxFileSize=20MB
log4j.appender.R.maxBackupIndex=50
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss,SSS} %-5p
%c{1}:%L - %m%n
log4j.appender.R.File=/var/log/cassandra/system.log

and in the rsyslog configuration had the following imfile directive:
# Cassandra log
input(type="imfile"
   File="/var/log/cassandra/system.log"
   Tag="cassandra:"
   StateFile="stat-localring93-1"
   ReadMode="2"
   Severity="info"
   Facility="local2")


# Templates for logging remotely
template(name="GroupApp" type="string"
        string="<%PRI%>%TIMESTAMP:::date-rfc3339% %HOSTNAME%
%syslogtag%shard93/localring:%msg%\n"
        )
if $syslogfacility-text == 'local0' or $syslogfacility-text == 'local1' or
$syslogfacility-text == 'local2' then {
  action(type="omrelp" target="LALALA" port="NNN" template="GroupApp"
         queue.filename="app_queue"
         queue.type="linkedlist"
         queue.spoolDirectory="/mnt/spool/rsyslog"
         queue.highwatermark="8000"
         queue.lowwatermark="6000"
         queue.maxdiskspace="1g"
         queue.timeoutenqueue="0"
         queue.saveonshutdown="on"
         queue.size="10000" )
  stop
}

The application logs locally and sends stuff to the rsyslog server but as I
wrote on previous email not everything is being sent.

However, I read this article http://www.rsyslog.com/tag/**log4j/ so I am
not sure everything works correctly using log4j. I am trying to use this
SyslogTCPAppneder but still struggling on how to setup it.

Thanks a log,
Xavi





On 9 July 2014 19:48, David Lang <[email protected]> wrote:

you don't show the part of the config that is logging locally, so it's
hard to tell why it would be different than what you are logging remotely

David Lang


On Wed, 9 Jul 2014, Xavier Fustero wrote:

 Hi,


using v8-stable still see that when using log4j not all logs on local are
reaching the remote rsyslog server. This seems a known problem in the
community:

http://www.rsyslog.com/tag/**lo20500g4j/
<http://www.rsyslog.com/tag/**log4j/>

Let me try if I can use that.

Thanks a log,
Xavi


On 8 July 2014 16:46, Xavier Fustero <[email protected]> wrote:

 Hi,



On 8 July 2014 14:50, Rainer Gerhards <[email protected]> wrote:

 Two things:


a) let us know what the actual problem is ;)

Ops! Forgot the most important part....

I couldn't see the logs on the remote server but actually I realized I
did
a misconfiguration.Fixed that but I see not all logs are arriving to the
remote server. Here is an example.

Local file:

INFO  *AbstractCassandraDaemon:322* - Cassandra shutting down...

INFO  CassandraDaemon:219 - Stop listening to thrift clients
INFO  Gossiper:1134 - Announcing shutdown
INFO  MessagingService:549 - Waiting for messaging service to quiesce
*ERROR AbstractCassandraDaemon:135* - Exception in thread Thread[ACCEPT-/
10.151.61.202,5,main]

*java.lang.RuntimeException: java.net.SocketException: Socket closed
at
org.apache.cassandra.net.MessagingService$SocketThread.
run(MessagingService.java:710)*

Caused by: java.net.SocketException: Socket closed
.....

Remote server:
Jul  8 14:28:21 localring93-1 cassandra: shard93/localring:*INFO*
*AbstractCassandraDaemon:322* - Cassandra shutting down...
Jul  8 14:28:23 localring93-1 cassandra: shard93/localring:*ERROR
AbstractCassandraDaemon:135* - Exception in thread Thread[ACCEPT-/
10.151.61.202,5,main]
Jul  8 14:28:23 localring93-1 cassandra: shard93/localring:*java.lang.
RuntimeException:
java.net.SocketException: Socket closed#012#011at
org.apache.cassandra.net.MessagingService$SocketThread.
run(MessagingService.java:710)*



Local files are not logging the timestamp to avoid repeting it on remote
server. But as you can see there are some missing lines on the remote
server. That's not good.



 b) 8.1.6 is an outdated past *development* version. No idea what was

broken
at that time, don't even know if epoll mode worked correctly. Suggest to
update to 8.3.3.

Oh thanks. Using add-apt-repository -y ppa:adiscon/v8-stable. Got
rsyslogd
8.2.0. That was the easier way for me to try deb packages on my Ubuntu
server. The errors I wrote above are using this 8.2.0.

Thanks,
Xavi

Rainer


On Tue, Jul 8, 2014 at 1:43 PM, Xavier Fustero <[email protected]>
wrote:

 Hi,


I modified a Cassandra application to write to a file and use imfile in
rsyslog to avoid the multiline logs headache.

I am running rsyslogd 8.1.6 on both client and server. The rsyslog

client

is configured with this imfile:

# Cassandra log
input(type="imfile"
        File="/var/log/cassandra/system.log"
        Tag="cassandra"
        StateFile="stat-localring93-1"
        readMode="2"
        Severity="info"
        Facility="local2")

Using a template for a dynamic file
# Templates for logging remotely
template(name="GroupApp" type="string"
         string="<%PRI%>%TIMESTAMP:::date-rfc3339% %HOSTNAME%
%syslogtag%testingdirectory:%msg%\n"
         )

if $syslogfacility-text == 'local0' or $syslogfacility-text == 'local1'

or

$syslogfacility-text == 'local2' then {
   action(type="omrelp" target="my_rsyslog_server" port="XXX"
template="GroupApp"

This template is used for many applications and it works.

I am tunning cassandra permissions but I am testing it with the

following

persmissions:
-rw-r--r-- 1 cassandra cassandra 68819 Jul  8 11:25 system.log

I have launched the rsyslog in debug mode and found lines like the ones
below. Don't understand what is wrong here....

Thanks a lot,
Xavi



8724.960462242:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8724.960497617:7f8465f45700: watch was MODIFID
8724.960508553:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8724.960524766:7f8465f45700: strm 0x7f8458000970: file 2 read 143 bytes
8724.960540272:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8724.960568041:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8724.961306511:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8724.961323707:7f8465f45700: watch was MODIFID
8724.961333731:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8724.961346822:7f8465f45700: strm 0x7f8458000970: file 2 read 123 bytes
8724.961360541:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8724.961379270:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8724.975517956:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8724.975537713:7f8465f45700: watch was MODIFID
8724.975555400:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8724.975570538:7f8465f45700: strm 0x7f8458000970: file 2 read 227 bytes
8724.975586518:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8724.975607192:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.223181801:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.223222283:7f8465f45700: watch was MODIFID
8726.223233392:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.223252494:7f8465f45700: strm 0x7f8458000970: file 2 read 108 bytes
8726.223267511:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.223300058:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.250839063:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.250860390:7f8465f45700: watch was MODIFID
8726.250870414:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.250884511:7f8465f45700: strm 0x7f8458000970: file 2 read 94 bytes
8726.250898340:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.250919260:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.362849538:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.362886487:7f8465f45700: watch was MODIFID
8726.362897480:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.362916266:7f8465f45700: strm 0x7f8458000970: file 2 read 73 bytes
8726.362930826:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.362961331:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.365043313:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.365059195:7f8465f45700: watch was MODIFID
8726.365068844:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.365082313:7f8465f45700: strm 0x7f8458000970: file 2 read 143 bytes
8726.365097233:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.365116020:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.370472579:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.370489599:7f8465f45700: watch was MODIFID
8726.370499573:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.370513159:7f8465f45700: strm 0x7f8458000970: file 2 read 123 bytes
8726.370526933:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.370546615:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.395377647:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.395404487:7f8465f45700: watch was MODIFID
8726.395415234:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.395431543:7f8465f45700: strm 0x7f8458000970: file 2 read 228 bytes
8726.395447460:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.395491800:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.415947524:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.415976445:7f8465f45700: watch was MODIFID
8726.415987581:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.416004499:7f8465f45700: strm 0x7f8458000970: file 2 read 93 bytes
8726.416018990:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.416041850:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.445146859:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.445169265:7f8465f45700: watch was MODIFID
8726.445179750:7f8465f45700: DDDD: imfile: wd 2 got file 0, dir -1
8726.445194270:7f8465f45700: strm 0x7f8458000970: file 2 read 105 bytes
8726.445208414:7f8465f45700: strm 0x7f8458000970: file 2 read 0 bytes
8726.445229364:7f8465f45700: stream checking for file change on
'/var/log/cassandra/system.log', inode 147/147
8726.847758210:7f8465f45700: DDDD: imfile event notification: rd 16[0],

wd

(2, mask 00000002, cookie 0000, len 0)
8726.847795247:7f8465f45700: watch was MODIFID
_______________________________________________
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.

Re: [rsyslog] imfile not sending logs to central rsyslog server

Reply via email to