[syslog-ng] Problem in source file driver

[Geller, Sandor (IT)]

Hi,

> I use syslog-ng 2.0.9.

Good.

> I am troubled in how to use the source file driver.
> The trouble is that a log message is output in duplicate
> after syslog-ng restart.
>
> I made following syslog-ng.conf.
> ------------------------------------------------------------
> options {
>   long_hostnames(off);
>   sync(0);
>   stats(0);
>   time_reopen(10);
>   dir_perm(0755);
>   perm(0644);
> };
>
> source s_test1 {
>   internal();
>   file("/tmp/test_app_log" follow_freq(1) flags(no-parse)
> keep_timestamp(no));
> };
>
> destination d_test1 { file("/var/log/test.log"); };
>
> log { source(s_test1); destination(d_test1); };
> ------------------------------------------------------------
>
> Next I tested syslog-ng action with following operation.
> ------------------------------------------------------------
> # echo "test message `date`" >> /tmp/test_app_log
> # cat /var/log/test.log
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:54 testserv2 test message Mon Jun 30 10:58:53 JST 2008
> # /etc/init.d/syslog-ng restart
> Stopping syslog-ng:                                        [  OK  ]
> Starting syslog-ng:                                        [  OK  ]
> # cat /var/log/test.log
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:46 testserv2 syslog-ng[17216]: Configuration
> reload request received, reloading configuration;
> Jun 30 10:58:54 testserv2 test message Mon Jun 30 10:58:53 JST 2008
> Jun 30 10:59:05 testserv2 syslog-ng[17216]: Termination
> requested via signal, terminating;
> Jun 30 10:59:05 testserv2 syslog-ng[17216]: syslog-ng
> shutting down; version='2.0.9'
> Jun 30 10:59:05 testserv2 syslog-ng[17292]: syslog-ng
> starting up; version='2.0.9'
> Jun 30 10:59:05 testserv2 test message Mon Jun 30 10:58:53 JST 2008
> ------------------------------------------------------------
>
> The message "testserv2 test message Mon Jun 30 10:58:53 JST
> 2008" was output in duplicate after syslog-ng retart.
> I hope the message is not output in duplicate after syslog-ng restart.
> Is my hope readily achievable?
>
> Please advise me.

Does your persist file exist at all? syslog-ng stores the file
positions in the persist file. Unfortunately I don't know other
way to see processing of the persist file other than running
syslog-ng under strace :(

Here is the relevant strace output:

open("/var/lib/syslog-ng.persist", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=78, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2a9556c000
read(3, "SLP1\0\0\0\34affile_sd_curpos(/proc/kmsg)\0\0\0\0010\0\0\0\33affile_sd_curpos(/tmp/alma)\0\0\0\00258", 4096) = 78
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0x2a9556c000, 4096)              = 0
socket(PF_FILE, SOCK_DGRAM, 0)          = 3
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
fcntl(3, F_GETFD)                       = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
stat("/dev/log", {st_mode=S_IFSOCK|0666, st_size=0, ...}) = 0
unlink("/dev/log")                      = 0
bind(3, {sa_family=AF_FILE, path="/dev/log"}, 11) = 0
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
chmod("/dev/log", 0666)                 = 0
open("/proc/kmsg", O_RDONLY|O_NOCTTY|O_NONBLOCK) = 4
fcntl(4, F_GETFD)                       = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
lseek(4, 0, SEEK_END)                   = 0
lseek(4, 0, SEEK_SET)                   = 0
open("/tmp/alma", O_RDONLY|O_NOCTTY|O_NONBLOCK) = 5
fcntl(5, F_GETFD)                       = 0
fcntl(5, F_SETFD, FD_CLOEXEC)           = 0
lseek(5, 0, SEEK_END)                   = 58
lseek(5, 58, SEEK_SET)                  = 58

I used /tmp/alma for testing, and as you can see syslog-ng seeked
for the stored file position.

Regards,

Sandor
--------------------------------------------------------

NOTICE: If received in error, please destroy and notify sender. Sender does not intend to waive confidentiality or privilege. Use of this email is prohibited when received in error.