date-column not showing right date!

You need additional help with phplogcon, then write into this forum.

Google Ads


date-column not showing right date!

Postby MCBurner » Mon Nov 19, 2012 12:48 pm

Hi.

I've successfully used LogAnalyzer on a Ubuntu box for months but since last Wednesday I have a very tricky problem with the syslog list. The date in the left column is not correct (out of sync). The simple reason: it's even not correct in the mysql table behind it! All syslog entries in the mysql database are generated with field type "datetime" and if I do a "select now();" within the same mysql installation it's absolutley correct - synced with the system date.

"date" on Ubuntu gives "Mo 19. Nov 12:41:49 CET 2012"
"select now();" on mysql (a few seconds later) gives "2012-11-19 12:42:31"

It seems that it the time difference increases. So now it's just an hour - but tonight it could 10 hours.
So what could be the problem here? The rsyslog daemon on the same server who receives all the syslogs?

Any help would be appreciated. Thanks.
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Urgent Question?

  • Pulling out your Hair?
  • Wasting Time and Money?
  • Deadline Approaching?

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 9:59 am

Just to confirm my own lines - it's in fact that the time difference increases dramatically! I've restarted mysql 10 minutes ago and the differences between the "ReceivedAt" and the real time is now 30 minutes. But right after the restart it was just some seconds.
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 10:20 am

Hm - after some more testing it looks like that I have something like a cache or spool behaviour somewhere in the process of receiving new syslogs and insert them into the DB. If I now send a test syslog to the system it takes a while until it get's displayed. Crazy.....
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 10:51 am

Just checking this post: viewtopic.php?f=36&t=8828 as it's a very similar situation...
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby rgerhards » Tue Nov 20, 2012 11:36 am

which rsyslog version do you use? what's in your rsyslog.conf? how many messages per second (or minute) do you receive?
rgerhards
Site Admin
 
Posts: 3806
Joined: Thu Feb 13, 2003 11:57 am

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 2:32 pm

Thanks for the replay. Unfortunately I have no idea where/how to check the version of rsyslog. To check the message per second I've activated impstats module some minutes ago.

Here's the content of "my" rsyslog.conf:

Code: Select all
#  /etc/rsyslog.conf    Configuration file for rsyslog.
#
#                       For more information see
#                       /usr/share/doc/rsyslog-doc/html/rsyslog_conf.html
#
#  Default logging rules can be found in /etc/rsyslog.d/50-default.conf


#################
#### MODULES ####
#################

$ModLoad impstats
$PStatInterval 600
$PStatSeverity 7
$ModLoad imuxsock # provides support for local system logging
$ModLoad imklog   # provides kernel logging support (previously done by rklogd)
#$ModLoad immark  # provides --MARK-- message capability

# provides UDP syslog reception
$ModLoad imudp
$UDPServerRun 514

# provides TCP syslog reception
$ModLoad imtcp
$InputTCPServerRun 514


syslog.debug /var/log/rsyslog-stats

###########################
#### GLOBAL DIRECTIVES ####
###########################

#
# Use traditional timestamp format.
# To enable high precision timestamps, comment out the following line.
#
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

# Filter duplicated messages
$RepeatedMsgReduction on

#
# Set the default permissions for all log files.
#
$FileOwner syslog
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$PrivDropToUser syslog
$PrivDropToGroup syslog

#
# Where to place spool files
#
$WorkDirectory /var/spool/rsyslog

$ActionQueueType LinkedList # use asynchronous processing
$ActionQueueFileName dbq    # set file name, also enables disk mode
$ActionResumeRetryCount -1  # infinite retries on insert failure

#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby rgerhards » Tue Nov 20, 2012 3:03 pm

assuming that rsyslogd is installed in /sbin, you can check the version as follows:

/sbin/rsyslogd -v

This can be done while the regular rsyslogd is running.
rgerhards
Site Admin
 
Posts: 3806
Joined: Thu Feb 13, 2003 11:57 am

Re: date-column not showing right date!

Postby rgerhards » Tue Nov 20, 2012 3:05 pm

The config looks at least a bit erratic. It ends with a partial action specification (the queue types and this) and THEN some include follows. That means the action parameters are assigend to the next action which accidently happens to be present as first one in the include path. That can have quite different results. Also, the config does not tell exactly what is present in the includes (which seem to include at leat the database writer).
rgerhards
Site Admin
 
Posts: 3806
Joined: Thu Feb 13, 2003 11:57 am

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 3:22 pm

rgerhards wrote:The config looks at least a bit erratic. It ends with a partial action specification (the queue types and this) and THEN some include follows. That means the action parameters are assigend to the next action which accidently happens to be present as first one in the include path. That can have quite different results. Also, the config does not tell exactly what is present in the includes (which seem to include at leat the database writer).


ups - you're right - I should have added the contents of the .conf files within /etc/rsyslog.d (20-ufw.conf 50-default.conf mysql.conf) - and here they are...

20-ufw.conf:
Code: Select all
# Log kernel generated UFW log messages to file
:msg,contains,"[UFW " /var/log/ufw.log

# Uncomment the following to stop logging anything that matches the last rule.
# Doing this will stop logging kernel generated UFW log messages to the file
# normally containing kern.* messages (eg, /var/log/kern.log)
#& ~


mysql.conf:
Code: Select all
### Configuration file for rsyslog-mysql
### Changes are preserved

$ModLoad ommysql
*.* :ommysql:localhost,Syslog,rsyslog,XXXX


50-default.conf:
Code: Select all
#  Default rules for rsyslog.
#
#                       For more information see rsyslog.conf(5) and /etc/rsyslog.conf

local3.info             ~
local3.debug            ~
local3.err              -/var/log/syslog

#
# First some standard log files.  Log by facility.
#
auth,authpriv.*                 /var/log/auth.log
auth,authpriv.none              -/var/log/syslog
#cron.*                         /var/log/cron.log
#daemon.*                       -/var/log/daemon.log
kern.*                          -/var/log/kern.log
#lpr.*                          -/var/log/lpr.log
mail.*                          -/var/log/mail.log
#user.*                         -/var/log/user.log

#
# Logging for the mail system.  Split it up so that
# it is easy to write scripts to parse these files.
#
#mail.info                      -/var/log/mail.info
#mail.warn                      -/var/log/mail.warn
mail.err                        /var/log/mail.err

#
# Logging for INN news system.
#
news.crit                       /var/log/news/news.crit
news.err                        /var/log/news/news.err
news.notice                     -/var/log/news/news.notice

#
# Some "catch-all" log files.
#
#*.=debug;\
#       auth,authpriv.none;\
#       news.none;mail.none     -/var/log/debug
#*.=info;*.=notice;*.=warn;\
#       auth,authpriv.none;\
#       cron,daemon.none;\
#       mail,news.none          -/var/log/messages

#
# Emergencies are sent to everybody logged in.
#
*.emerg                                :omusrmsg:*

#
# I like to have messages displayed on the console, but only on a virtual
# console I usually leave idle.
#
#daemon,mail.*;\
#       news.=crit;news.=err;news.=notice;\
#       *.=debug;*.=info;\
#       *.=notice;*.=warn       /dev/tty8

# The named pipe /dev/xconsole is for the `xconsole' utility.  To use it,
# you must invoke `xconsole' with the `-file' option:
#
#    $ xconsole -file /dev/xconsole [...]
#
# NOTE: adjust the list below, or you'll go crazy if you have a reasonably
#      busy site..
#
daemon.*;mail.*;\
        news.err;\
        *.=debug;*.=info;\
        *.=notice;*.=warn       |/dev/xconsole
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 3:47 pm

rgerhards wrote:assuming that rsyslogd is installed in /sbin, you can check the version as follows:

/sbin/rsyslogd -v

This can be done while the regular rsyslogd is running.


Hm that wasn't successfull but during service restart I got this info:

origin software="rsyslogd" swVersion="5.8.6"
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 3:54 pm

And here's an up-to-date copy of the "rsyslog-stats" content:

Code: Select all
2012-11-20T14:35:12.531855+01:00 XXXXX rsyslogd-pstats: imuxsock: submitted=6 ratelimit.discarded=0 ratelimit.numratelimiters=3
2012-11-20T14:35:12.531875+01:00 XXXXX rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T14:35:12.531890+01:00 XXXXX rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T14:35:12.531898+01:00 XXXXX rsyslogd-pstats: main Q: size=310 enqueued=434 full=0 maxqsize=316
2012-11-20T14:45:12.536948+01:00 XXXXX rsyslogd-pstats: imuxsock: submitted=18 ratelimit.discarded=0 ratelimit.numratelimiters=9
2012-11-20T14:45:12.536962+01:00 XXXXX rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T14:45:12.536969+01:00 XXXXX rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T14:45:12.536975+01:00 XXXXX rsyslogd-pstats: main Q: size=628 enqueued=848 full=0 maxqsize=628
2012-11-20T15:44:19.452813+01:00 XXXXX rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" x-pid="554" x-info="http://www.rsyslog.com"] start
2012-11-20T15:44:19.452946+01:00 XXXXX rsyslogd: rsyslogd's groupid changed to 103
2012-11-20T15:44:19.452993+01:00 XXXXX rsyslogd: rsyslogd's userid changed to 101
2012-11-20T15:44:19.454692+01:00 XXXXX rsyslogd-2077: Could not create tcp listener, ignoring port 514. [try http://www.rsyslog.com/e/2077 ]
2012-11-20T15:49:29.118483+01:00 XXXXX rsyslogd: [origin software="rsyslogd" swVersion="5.8.6" x-pid="602" x-info="http://www.rsyslog.com"] start
2012-11-20T15:49:29.118609+01:00 XXXXX rsyslogd: rsyslogd's groupid changed to 103
2012-11-20T15:49:29.118661+01:00 XXXXX rsyslogd: rsyslogd's userid changed to 101


meanwhile I disabled the tcp 514 listener in the rsyslog.conf file and also disabled the use of the 50-default.conf file.
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 4:27 pm

another sorry - just realized that i'm using a very veeeeeeeeeeeery old version of rsyslog. let me try to update to the newest v7 release and see where it ends.
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Tue Nov 20, 2012 5:25 pm

Puh! After some trouble with missing libs and compiler elements I'm now using "rsyslog-7.2.2". BUT - the situation is still the same. The only interesting part so far is the last entry in "rsyslog-stats". It says:
"rsyslogd: db error (2002): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)"

With this error message only I would assume that rsyslog has stopped writing new entries into the MySQL db. But I still get new entries. To double-check i've checked running syslog processes which says:
Code: Select all
syslog     713  0.0  0.0 430272  3136 ?        Sl   17:19   0:00 rsyslogd -c5
root      2151  0.0  0.0   9576   888 pts/0    S+   17:30   0:00 grep --color=auto rsyslog


Totally confused now :-)
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby MCBurner » Wed Nov 21, 2012 10:21 am

Maybe helpfull.... another copyNpaste of the latest "rsyslog-stats". The funny thing is - I've copied it 10 minutes ago. So rsyslog "thinks" it's now the 20th of November 22:49 :-) But Ubuntus system time/date and mysql are still correct.
Code: Select all
2012-11-20T22:19:28.005216+01:00 whvub01 rsyslogd-pstats: imuxsock: submitted=259 ratelimit.discarded=0 ratelimit.numratelimiters=116
2012-11-20T22:19:28.005233+01:00 whvub01 rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:19:28.005237+01:00 whvub01 rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:19:28.005242+01:00 whvub01 rsyslogd-pstats: main Q: size=7475 enqueued=11924 full=0 maxqsize=7475
2012-11-20T22:29:28.105274+01:00 whvub01 rsyslogd-pstats: imuxsock: submitted=262 ratelimit.discarded=0 ratelimit.numratelimiters=118
2012-11-20T22:29:28.105292+01:00 whvub01 rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:29:28.105297+01:00 whvub01 rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:29:28.105301+01:00 whvub01 rsyslogd-pstats: main Q: size=7790 enqueued=12367 full=0 maxqsize=7790
2012-11-20T22:39:28.169981+01:00 whvub01 rsyslogd-pstats: imuxsock: submitted=268 ratelimit.discarded=0 ratelimit.numratelimiters=122
2012-11-20T22:39:28.170002+01:00 whvub01 rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:39:28.170008+01:00 whvub01 rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:39:28.170013+01:00 whvub01 rsyslogd-pstats: main Q: size=8095 enqueued=12800 full=0 maxqsize=8095
2012-11-20T22:49:28.270045+01:00 whvub01 rsyslogd-pstats: imuxsock: submitted=271 ratelimit.discarded=0 ratelimit.numratelimiters=124
2012-11-20T22:49:28.270062+01:00 whvub01 rsyslogd-pstats: action 2 queue[DA]: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:49:28.270067+01:00 whvub01 rsyslogd-pstats: action 2 queue: size=0 enqueued=0 full=0 maxqsize=0
2012-11-20T22:49:28.270071+01:00 whvub01 rsyslogd-pstats: main Q: size=8299 enqueued=13132 full=0 maxqsize=8305
MCBurner
Avarage
 
Posts: 15
Joined: Mon Nov 19, 2012 12:31 pm

Re: date-column not showing right date!

Postby rgerhards » Wed Nov 21, 2012 10:37 am

mmhhh... do we have chance to get a debug log when this situation occurs? It's a bit tricky to setup, unfortunately:

http://www.rsyslog.com/how-to-use-debug-on-demand/

If I get you correctly, the problem does not immediately occur after startup, but only after some time - right?
rgerhards
Site Admin
 
Posts: 3806
Joined: Thu Feb 13, 2003 11:57 am

Google Ads


Next

Return to Help

Who is online

Users browsing this forum: No registered users and 0 guests

cron