Scribe scribe - syslog-ng and logrotate installer

[cmkelley]

I keep getting this error in syslog.ng-log:

Feb 13 08:47:01 AC3100 syslog-ng[10549]: The current log file has a mismatching size/inode information, restarting from the beginning; state='affile_sd_curpos(/var/lib/logrotate.status)', stored_inode='7925593', cur_file_inode='7937689', stored_size='207', cur_file_size='207', raw_stream_pos='0'

Not sure how to fix it, or if its even a scribe issue, but I see it in uiScribe in the WebUI which lately has been locking up and becoming non-responsive until I restart scribe.

I've tried two complete uninstalls, reboots, etc.

RT-AC3100 (armv7l) FW-384.15

I'm not sure either ... there are similar messages (I'm away from home right now, so I can't check exactly) when a log file is rotated, its inode changes, so syslog-ng restarts it. BUT, that should all happen in the middle of the night. At this point, I'd guess you have a bad USB drive, or maybe it's full.

Usually a non-responsive webUI is from log files that have gotten too big, but restarting scribe (which really just restarts syslog-ng and uiScribe) shouldn't change the log file size.

 

[Butterfly Bones]

I'm not sure either ... there are similar messages (I'm away from home right now, so I can't check exactly) when a log file is rotated, its inode changes, so syslog-ng restarts it. BUT, that should all happen in the middle of the night. At this point, I'd guess you have a bad USB drive, or maybe it's full.

Usually a non-responsive webUI is from log files that have gotten too big, but restarting scribe (which really just restarts syslog-ng and uiScribe) shouldn't change the log file size.

It is when Skynet purges its log file of [DROP] etc. at the top of every hour and does [SAVE]. I see one every hour throughout the day.

Feb 13 08:00:01 RT-AC86U-4608 syslog-ng[28956]: Configuration reload request received, reloading configuration;
Feb 13 08:00:01 RT-AC86U-4608 syslog-ng[28956]: Configuration reload finished;
Feb 13 09:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload request received, reloading configuration;
Feb 13 09:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload finished;
Feb 13 10:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload request received, reloading configuration;
Feb 13 10:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload finished;
Feb 13 11:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload request received, reloading configuration;
Feb 13 11:00:02 RT-AC86U-4608 syslog-ng[28956]: Configuration reload finished;

 

[elorimer]

This logrotate.status file is a little weird. You can often get a ton of messages from syslog-ng that it can't be found, and then it goes away, maybe after the first rotation. I think this inode mismatch might come about because two operations are going on at the same time. I haven't dug into why though.

 

[Butterfly Bones]

This logrotate.status file is a little weird. You can often get a ton of messages from syslog-ng that it can't be found, and then it goes away, maybe after the first rotation. I think this inode mismatch might come about because two operations are going on at the same time. I haven't dug into why though.

Isn't this the same or similar to what was happening in Skynet with the syslog-ng 3.23 release? We needed to use a "time_reap (2)" until Adamm made a change in Skynet, That is when this "Configuration reload.." began. In my /opt/var/log/syslog-ng.log I see these for every hour of every day. It does not change how Skynet or syslog-ng works or logs anything.

 

[elorimer]

Isn't this the same or similar to what was happening in Skynet with the syslog-ng 3.23 release? We needed to use a "time_reap (2)" until Adamm made a change in Skynet, That is when this "Configuration reload.." began. In my /opt/var/log/syslog-ng.log I see these for every hour of every day. It does not change how Skynet or syslog-ng works or logs anything.

Kinda. syslog-ng holds log files it is writing too open for a while. When logrotate runs, syslog-ng would be writing to the place where the old, unrotated, files would have been, so the logrotate configs send a hangup signal to syslog-ng, which closes all its files, reloads the configuration again and starts writing to the write place again. @Adamm added sending a hangup signal to the purge_logs section of the skynet script to do the same thing, so we didn't need to force syslog-ng to close a file after a second or two.

https://syslog-ng.balabit.narkive.com/fUH0rqZw/mismatching-size-inode-information

But I don't see why syslog-ng would ever be reading the logrotate.status file, so why is it kicking off this error message? Utterly wrong.

 

[cmkelley]

Kinda. syslog-ng holds log files it is writing too open for a while. When logrotate runs, syslog-ng would be writing to the place where the old, unrotated, files would have been, so the logrotate configs send a hangup signal to syslog-ng, which closes all its files, reloads the configuration again and starts writing to the write place again. @Adamm added sending a hangup signal to the purge_logs section of the skynet script to do the same thing, so we didn't need to force syslog-ng to close a file after a second or two.

https://syslog-ng.balabit.narkive.com/fUH0rqZw/mismatching-size-inode-information

But I don't see why syslog-ng would ever be reading the logrotate.status file, so why is it kicking off this error message?

syslog-ng does read /var/lib/logrotate.status to generate the unified log. Amusingly enough, logrotate doesn't seem to log through the system syslog facility ... go figure.

/opt/etc/syslog-ng.d/logrotate:

# gather logrotate logs together for unified log

destination d_logrotate {
   file("/opt/var/log/logrotate.log");
};

source s_lr_status {
   file("/var/lib/logrotate.status" program-override("logrotate") flags(no-parse));
};

source s_lr_daily {
   file("/opt/tmp/logrotate.daily" program-override("logrotate") flags(no-parse));
};

log {
   source(s_lr_status);
   source(s_lr_daily);
   destination(d_logrotate);
   flags(final);
};

#eof

 

[elorimer]

I never had a clue the logrotate config was doing this or logrotate wasn't logging normally.

 

[elorimer]

I guess that also explains why syslog-ng is kicking off an error until the first logrotate.

 

[Butterfly Bones]

This is new, I have no clue. In the webgui syslog (/opt/var/log/messages). Does not show in /opt/var/log/syslog-ng.log.

Feb 15 03:58:10 RT-AC86U-4608 kernel: P           O    4.1.27 #2
580 DPT=81 SEQ=3099330335 ACK=0 WINDOW=14600 RES=0x00 SYN URGP=0 OPT (020405B4) MARK=0x8000000 
00 
00001030307) MARK=0x8000000 
25/administration-guide
#
# Release notes: https://github.com/syslog-ng/syslog-ng/releases 
#
# non-scl version with "@include "scl.conf"" and call to default-network-drivers function (part of scl) removed
#   moved sourcing /proc/kmsg from "source kernel" to "source src" and added directives to /proc/kmsg and /dev/log sourcing
#   log_msg_size increased to 16K to ensure even large messages are completely captured
#   stats_freq changed to every 6 hours
#   source net function to get udp log messages from local network commented out
#   destination log_server function added (commented out) to illustrate sending udp log messages to server on local network
#
#   NB: time_reap default behaviour was changed significantly in version 3.25
Feb 15 05:07:39 RT-AC86U-4608 kernel: P           O    4.1.27 #2
2142 DPT=2167 SEQ=668754277 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000 
x8000000 
) MARK=0x8000000 
ARK=0x8000000 
/administration-guide
#
# Release notes: https://github.com/syslog-ng/syslog-ng/releases 
#
# non-scl version with "@include "scl.conf"" and call to default-network-drivers function (part of scl) removed
#   moved sourcing /proc/kmsg from "source kernel" to "source src" and added directives to /proc/kmsg and /dev/log sourcing
#   log_msg_size increased to 16K to ensure even large messages are completely captured
#   stats_freq changed to every 6 hours
#   source net function to get udp log messages from local network commented out
#   destination log_server function added (commented out) to illustrate sending udp log messages to server on local network
#
#   NB: time_reap default behaviour was changed significantly in version 3.25

 

[cmkelley]

This is new, I have no clue. In the webgui syslog (/opt/var/log/messages). Does not show in /opt/var/log/syslog-ng.log.

Feb 15 03:58:10 RT-AC86U-4608 kernel: P           O    4.1.27 #2
580 DPT=81 SEQ=3099330335 ACK=0 WINDOW=14600 RES=0x00 SYN URGP=0 OPT (020405B4) MARK=0x8000000
00
00001030307) MARK=0x8000000
25/administration-guide
#
# Release notes: https://github.com/syslog-ng/syslog-ng/releases
#
# non-scl version with "@include "scl.conf"" and call to default-network-drivers function (part of scl) removed
#   moved sourcing /proc/kmsg from "source kernel" to "source src" and added directives to /proc/kmsg and /dev/log sourcing
#   log_msg_size increased to 16K to ensure even large messages are completely captured
#   stats_freq changed to every 6 hours
#   source net function to get udp log messages from local network commented out
#   destination log_server function added (commented out) to illustrate sending udp log messages to server on local network
#
#   NB: time_reap default behaviour was changed significantly in version 3.25
Feb 15 05:07:39 RT-AC86U-4608 kernel: P           O    4.1.27 #2
2142 DPT=2167 SEQ=668754277 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
x8000000
) MARK=0x8000000
ARK=0x8000000
/administration-guide
#
# Release notes: https://github.com/syslog-ng/syslog-ng/releases
#
# non-scl version with "@include "scl.conf"" and call to default-network-drivers function (part of scl) removed
#   moved sourcing /proc/kmsg from "source kernel" to "source src" and added directives to /proc/kmsg and /dev/log sourcing
#   log_msg_size increased to 16K to ensure even large messages are completely captured
#   stats_freq changed to every 6 hours
#   source net function to get udp log messages from local network commented out
#   destination log_server function added (commented out) to illustrate sending udp log messages to server on local network
#
#   NB: time_reap default behaviour was changed significantly in version 3.25

I've had that happen a few times. Sometimes similar stuff shows up in skynet-0.log as well. I have no clue, but it doesn't seem to hurt anything other than make the log a bit more difficult to follow.

 

[Butterfly Bones]

Yeah, no big deal, just now showing after all these months, it was just an alert for you, in case you needed to know. Since you have seen it too, we will just move on.

 

[cmkelley]

Yeah, no big deal, just now showing after all these months, it was just an alert for you, in case you needed to know. Since you have seen it too, we will just move on.

I do appreciate the heads up. I don't have a clue where to even start looking, and since it's not hurting anything, I'm having a hard time getting any motivation to look harder.

 

[elorimer]

Part of that logging -- quoting from the syslog-ng.conf file -- is really weird. The other part--the fragmented portion of the skynet logging--we saw back when we were fooling with the system source and klogd, if I recall correctly. It all looks like a buffer overrun.

 

[Butterfly Bones]

The thing is weird, especially since it seems to trigger by some strange obscure kernel "P" error.

 

[skeal]

I'm a complete noob to this script and its webui. Can someone help me setup unbound logging to scribe please? I looked for some examples and found nothing related to unbound.

 

[Martineau]

I'm a complete noob to this script and its webui. Can someone help me setup unbound logging to scribe please? I looked for some examples and found nothing related to unbound.

Errr use unbound_manager ?

e  = Exit Script

A:Option ==> scribe

 

[skeal]

Errr use unbound_manager ?

e  = Exit Script

A:Option ==> scribe

Thank you sir!!

 

[skeal]

Sorry another noob question. How can I create a log for these entries?

Feb 16 18:31:22 RT-AX88U-9D28 hostapd: eth7: STA (mac address) WPA: group key handshake completed (RSN)

I want to strip them from the main log.

 

[skeal]

Sorry another noob question. How can I create a log for these entries?

Feb 16 18:31:22 RT-AX88U-9D28 hostapd: eth7: STA (mac address) WPA: group key handshake completed (RSN)

I want to strip them from the main log.

I had a look at the examples and I think can create the one file myself but the other is quite a bit more complex. Anyone have time to set me straight?

 

[elorimer]

I had a look at the examples and I think can create the one file myself but the other is quite a bit more complex. Anyone have time to set me straight?

I didn't follow what you mean here by "the other". You create a separate log destination, and then you create a filter that will trap the messages you want to send there, like filtering on "group key" or "group key handshake" in the MSG part, or hostapd in the PROGRAM part.