Scribe scribe - syslog-ng and logrotate installer

[elorimer]

When the router is starting up with syslog, before syslog-ng starts, it is logging to /tmp/syslog.log. When scribe starts syslog-ng up, it appends that file to messages, which means all those messages are listed with the May 5 time stamp, because ntp hasn't synced yet.

As I have described before, I zero out messages on startup, and copy syslog.log to a file. When syslog-ng starts up, the second configuration file that is processed (the first is loggly), reads that file and processes those messages first, and then goes on to the other sources. I've noticed that that wasn't working exactly right, so I have improved on it.

Specifically, I've redefined the source to this:

source s_startup {
    file("/opt/var/log/startup" keep-timestamp(no) log-fetch-limit(3000) follow-freq(1000));
};

The default log fetch limit is 100, and syslog.log has about 2400 messages, so I was getting other stuff in between and hadn't noticed it. The default for keep-timestamp is yes, so this puts in a time stamp at the time syslog-ng starts processing, which is after the ntp sync has occurred. Follow-freq tells syslog-ng not to look to see if the file has changed every second, but instead every 1,000 seconds, since I never need to look at it twice.

The result is that my messages log starts like so, with a time stamp starting at the time, a good chunk of time after the router actually rebooted, when syslog-ng started:

Jul 30 17:49:07 syslogd started: BusyBox v1.25.1
Jul 30 17:49:07 RT-AC86U kernel: klogd started: BusyBox v1.25.1 (2020-07-30 00:43:28 EDT)
Jul 30 17:49:07 RT-AC86U kernel: Booting Linux on physical CPU 0x0
Jul 30 17:49:07 RT-AC86U kernel: Linux version 4.1.27 (merlin@ubuntu-dev) (gcc version 5.3.0 (Buildroot 2016.02) ) #2 SMP PREEMPT Thu Jul 30 01:57:08 EDT 2020
Jul 30 17:49:07 RT-AC86U kernel: CPU: AArch64 Processor [420f1000] revision 0
....
2400 other messages, until the USB drive is mouinted, entware starts, and syslog-ng gets started by scribe
...
Jul 30 17:49:07 RT-AC86U custom_script: Running /jffs/scripts/post-mount (args: /tmp/mnt/Cruzer)
Jul 30 17:49:07 RT-AC86U kernel: Adding 2097148k swap on /tmp/mnt/Cruzer/myswap.swp.  Priority:-1 extents:15 across:2424832k
Jul 30 17:49:07 RT-AC86U Diversion: Starting Entware and Diversion services on /tmp/mnt/Cruzer
Jul 30 17:49:07 RT-AC86U kernel: klogd: exiting
Jul 30 17:49:07 syslogd exiting
Jul 30 17:49:07 RT-AC86U elorimer: Diversion Mounting Diversion WebUI as user1.asp
Jul 30 17:49:08 RT-AC86U Diversion: restarted Dnsmasq to apply settings

Whereupon it goes on its merry way. The result is I have a neat record of the current startup sequence. I lose the incrementing May 5 time, since it is all processed so fast, but I keep the order.

 

[Goobi]

How would one go about stripping items like this from the syslog and sending them to their own log files?

 (VPN_Failover.sh)[15718]: 5077 Will check VPN Client 5 connection status again in 00:01:00 .....@16:21:44
 (ChkWAN.sh)[17271]: 17111 v1.15 Monitoring WAN connection using 1 target PING hosts (www.google.com) (Tries=3)

 

[ugandy]

How would one go about stripping items like this from the syslog and sending them to their own log files?

(VPN_Failover.sh)[15718]: 5077 Will check VPN Client 5 connection status again in 00:01:00 .....@16:21:44
(ChkWAN.sh)[17271]: 17111 v1.15 Monitoring WAN connection using 1 target PING hosts (www.google.com) (Tries=3)

you need to create files under /opt/etc/syslog-ng.d and logrotate.d

look at the ones there and copy/modify

to filter this annoyance:
kernel: CFG80211-ERROR) wl_cfg80211_change_station : WLC_SCB_AUTHORIZE sta_flags_mask not set

I used

destination d_wlchangestation {
    file("/opt/var/log/wlchangestation.log");
};

filter f_kernel {
    program("kernel");
};

filter f_mymsg{
    message("CFG80211-ERROR") or
    message("wl_cfg80211_change_station");
};

log {
    source(src);
    filter(f_kernel);
    filter(f_mymsg);
    destination(d_wlchangestation);
    flags(final);
};

not sure if best approach, but it works, and the msg no longer spams my syslog, making it readable again

 

[Goobi]

you need to create files under /opt/etc/syslog-ng.d and logrotate.d

look at the ones there and copy/modify

to filter this annoyance:
kernel: CFG80211-ERROR) wl_cfg80211_change_station : WLC_SCB_AUTHORIZE sta_flags_mask not set

I used

destination d_wlchangestation {
    file("/opt/var/log/wlchangestation.log");
};

filter f_kernel {
    program("kernel");
};

filter f_mymsg{
    message("CFG80211-ERROR") or
    message("wl_cfg80211_change_station");
};

log {
    source(src);
    filter(f_kernel);
    filter(f_mymsg);
    destination(d_wlchangestation);
    flags(final);
};

not sure if best approach, but it works, and the msg no longer spams my syslog, making it readable again

I tried this but it did not work:

destination d_vpnfailover {
    file("/opt/var/log/vpnfailover.log");
};

filter f_vpnfailover {
    program("kernel")
};

filter f_mymsg{
    message("VPN_Failover.sh");
};

log {
    source(src);
    filter(f_kernel);
    filter(f_mymsg);
    destination(d_vpnfailover);
    flags(final);
};

 

[ugandy]

maybe remove the f_fernel filter since msg is not from kernel?

 

[cmkelley]

I tried this but it did not work:

destination d_vpnfailover {
    file("/opt/var/log/vpnfailover.log");
};

filter f_vpnfailover {
    program("kernel")
};

filter f_mymsg{
    message("VPN_Failover.sh");
};

log {
    source(src);
    filter(f_kernel);
    filter(f_mymsg);
    destination(d_vpnfailover);
    flags(final);
};

remove the filter "f_vpnfailover" (you're not actually using it) and also remove the line "filter(f_kernel);" from the log statement since as @ugandy points out, it isn't a message from the kernel, and "f_kernel" may not be defined in your environment anyways.

 

[Olivier L]

Like this, it works

destination d_vpnfailover {
    file("/opt/var/log/vpnfailover.log");
};

filter f_vpnfailover{
    program("VPN_Failover.sh");
};

log {
    source(src);
    filter(f_vpnfailover);
    destination(d_vpnfailover);
    flags(final);
};

 

[Goobi]

Like this, it works

destination d_vpnfailover {
    file("/opt/var/log/vpnfailover.log");
};

filter f_vpnfailover{
    program("VPN_Failover.sh");
};

log {
    source(src);
    filter(f_vpnfailover);
    destination(d_vpnfailover);
    flags(final);
};

Worked like a charm! Thanks much!

 

[giant46man46]

Hello All. I am a complete n00b to ASUSWRT-Merlin, but I generally know enough about networking, scripting, linux, etc to get by. Please excuse my n00b question, but does Skynet need to be installed in order for scribe to work? Does installing Skynet make getting scribe to work easier? I ask these questions because I attempted to install scribe and it is not working. The General -> System Messages log works, but the other logs are (firewall.log, logrotate.log, syslog-ng.log, wlceventd.log). Can someone please help me with this?

 

[cmkelley]

Hello All. I am a complete n00b to ASUSWRT-Merlin, but I generally know enough about networking, scripting, linux, etc to get by. Please excuse my n00b question, but does Skynet need to be installed in order for scribe to work? Does installing Skynet make getting scribe to work easier? I ask these questions because I attempted to install scribe and it is not working. The General -> System Messages log works, but the other logs are (firewall.log, logrotate.log, syslog-ng.log, wlceventd.log). Can someone please help me with this?

I'm not quite sure I understand your problem, but neither scribe nor Skynet rely on each other work. If you have, or are going to use Skynet, you should install Skynet first to ensure scribe properly handles Skynet's logs, but that's it.

I'm sorry, I can't understand the second part of your question. Is there a problem with the other logs?

 

[elorimer]

Hello All. I am a complete n00b to ASUSWRT-Merlin, but I generally know enough about networking, scripting, linux, etc to get by. Please excuse my n00b question, but does Skynet need to be installed in order for scribe to work? Does installing Skynet make getting scribe to work easier? I ask these questions because I attempted to install scribe and it is not working. The General -> System Messages log works, but the other logs are (firewall.log, logrotate.log, syslog-ng.log, wlceventd.log). Can someone please help me with this?

Skynet isn't necessary.

Scribe is a script that handles configuring syslog-ng on the router to replace the native syslogd. From there syslog-ng can take you in a lot of different directions, including parsing out the single system log into separate logs. But it doesn't have anything to do with anything else other than logging.

UiScribe is a script that builds on scribe by displaying in the GUI the different logs that scribe creates.

Skynet is something entirely different. That is a firewall program that denies inbound and outbound traffic to addresses it thinks are nasty. It generates log messages each time it does that. If scribe/syslog-ng isn't active, those messages go to the system log. If scribe/syslog-ng is active, it will send those messages to its own log. Hourly it purges those messages from the log destination (whichever one) and logs a summary. There was a bit of interaction there, because the purge process had the unintended effect of stopping syslog-ng and restarting syslogd. That has long since been fixed, and that is the only interaction between scribe and skynet.

As to this:

but the other logs are (firewall.log, logrotate.log, syslog-ng.log, wlceventd.log)

you're going to have to finish that sentence.

 

[flyg]

Im stuck in a loop. Getting the following

Updated list of available packages in /opt/var/opkg-lists/entware

Installing syslog-ng (3.27.1-1) to root...
Downloading http://bin.entware.net/armv7sf-k2.6/syslog-ng_3.27.1-1_armv7-2.6.ipk
Configuring syslog-ng.
syslog-ng: error while loading shared libraries: /opt/lib/librt.so.1: invalid ELF header

syslog-ng version 3.19 or higher required!
Please update your Entware packages and run scribe install again.

Removing package syslog-ng from root...

Any suggestions what to do? Updating Entware says all upto date.

 

[elorimer]

Im stuck in a loop.

@cmkelley will be along to apply expert help. He's the guru.

Methinks there are two separate problems going on. The first one is the error in loading /opt/lib/librt.so.1. Syslog-ng is trying to load, and failing. That suggests your USB drive is borked, and you might want to uninstall entware and start all over. But first does that file exist? If it does then you might start syslog-ng manually in a terminal and see what the error messages might be.

The second is the mesage about 3.19. That is generated by scribe when it runs syslog-ng --version. Run that in a terminal and see what is reported. I'm guessing it fails out and reports an error; scribe is trying to extract a version from the output and testing whether that is greater than 3.19. So testing whether "I can't start" is greater than 3.19 is going to fail, and generate that message.

 

[Megahurtz]

I attempted to follow some of the instructions on this page to filter out messages from transmission, afpd, and some kernel messages related to my hard drive. However, now I seem to have broken all logging. From what I can see, none of my logs have updated since I rebooted the router. I also don't see the three new log files I made listed in uiscribe.

Here are the steps I followed:
1. Touched new files in /opt/var/log for afpd.log, transmission.log, and sda.log.
2. Created new files related to all of the above in /opt/etc/logrotate.d/ that pointed to the logs files. They are all the same other than the path to the log file, so here is my afpd one:

/opt/var/log/afpd.log {
rotate 4
postrotate
/usr/bin/killall -HUP syslog-ng
endscript
}

3. Created my filters in /opt/etc/syslogng-d/. Here they are.
afpd:

destination d_afpd {
file("/opt/var/log/afpd.log");
};

filter f_afpd{
program("afpd");
};

filter f_mymsg{
message("ad_valid_header_osx");
};

log {
source(src);
filter(f_afpd);
filter(f_mymsg);
destination(d_afpd);
flags(final);
};

sda:

};

filter f_kernel{
program("kernel");
};

filter f_mymsg{
message("sd 0:0:0:0: [sda]") or
message("end_request: I/O error") or
message("xhci_hcd 0000:00:0c.0");
};

log {
source(src);
filter(f_kernel);
filter(f_mymsg);
destination(d_sda);
flags(final);
};

transmission:

destination d_transmission {
file("/opt/var/log/transmission.log");
};

filter f_transmission-daemon{
program("transmission-daemon");
};

log {
source(src);
filter(f_transmission-daemon);
destination(d_transmission);
flags(final);
};

3.Rebooted the router.

My intention was to send a recurring afpd/time machine message that spams my main log over and over to its own log, send all transmission entries to their own log, and send the following block of similar messages to its own log file:

kernel: sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
kernel: sd 0:0:0:0: [sda] Sense Key : Illegal Request [current]
kernel: sd 0:0:0:0: [sda] Add. Sense: Invalid command operation code
kernel: sd 0:0:0:0: [sda] CDB: Write same(16): 93 08 00 00 00 00 93 c4 c4 38 00 00 00 70 00 00
kernel: end_request: I/O error, dev sda, sector 2479146040
kernel: end_request: I/O error, dev sda, sector 2479146040
kernel: xhci_hcd 0000:00:0c.0: WARN: Stalled endpoint

Any ideas? Please help

 

[Butterfly Bones]

I attempted to follow some of the instructions on this page to filter out messages from transmission, afpd, and some kernel messages related to my hard drive. However, now I seem to have broken all logging. From what I can see, none of my logs have updated since I rebooted the router. I also don't see the three new log files I made listed in uiscribe.

Here are the steps I followed:
1. Touched new files in /opt/var/log for afpd.log, transmission.log, and sda.log.
2. Created new files related to all of the above in /opt/etc/logrotate.d/ that pointed to the logs files. They are all the same other than the path to the log file, so here is my afpd one:

3. Created my filters in /opt/etc/syslogng-d/. Here they are.
afpd:


sda:


transmission:

3.Rebooted the router.

My intention was to send a recurring afpd/time machine message that spams my main log over and over to its own log, send all transmission entries to their own log, and send the following block of similar messages to its own log file:


Any ideas? Please help

There is a afpd.log filter file in entware/share/syslog-ng/examples/ provided with Scribe. I think that is the one i wrote and tested about a year ago. It works for me. Here it is copied from that directory above.

# log Apple Time Machine messages to /opt/var/log/afpd.log
#   afpd = Apple Filing Protocal daemon
#   cnid_dbd = Catalog Node ID database daemon

destination d_afpd {
    file("/opt/var/log/afpd.log");
};

filter f_afpd {
    program("afpd") or
    program("cnid_dbd");
};

log {
    source(src);
    filter(f_afpd);
    destination(d_afpd);
    flags(final);
};

#eof

I do not use the others you need, but have you tried searching this thread for them? Many filter files have been posted here previously. Or use one of the filter files in entware/share/syslog-ng/examples/ from your USB drive as a template and alter it. You will learn a lot doing that, since you have an idea of what to do in your first attempts. Good luck.

 

[Megahurtz]

Ok, looking at uiScribe, it was complaining about my sda filter. I deleted that and now my afpd and transmission filters are working along with logging in general.

So, back to my sda filter, how would I go about writing a file to send the following messages to their own log? I think it didn't like the message section of my previous attempt.

kernel: sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
kernel: sd 0:0:0:0: [sda] Sense Key : Illegal Request [current]
kernel: sd 0:0:0:0: [sda] Add. Sense: Invalid command operation code
kernel: sd 0:0:0:0: [sda] CDB: Write same(16): 93 08 00 00 00 00 93 c4 c4 38 00 00 00 70 00 00
kernel: end_request: I/O error, dev sda, sector 2479146040
kernel: end_request: I/O error, dev sda, sector 2479146040
kernel: xhci_hcd 0000:00:0c.0: WARN: Stalled endpoint

And while we're at it, any idea why my log timestamps for kernel entries would have jumped ahead 5 hours immediately after a reboot? Non-kernel entires display the correct time.

 

[elorimer]

On the sda filter, I'm guessing you have another file that also defines a kernel filter. Syslog-ng won't start if a definition occurs twice, unless you specifically allow duplicates. So it wasn't scribe or uiScribe that was choking on the sda file, it was syslog-ng itself. But that is why your logs weren't updating; syslog-ng didn't start. I don't think you need that filter in your sda file in the first place, since the messages seem so specific. So try it with just the message filter. If you need it, delete it from all of your log files and put it in its own file once. Don't put it in syslog-ng.conf, cuz that will get overwritten.

A general debugging tool is to run "syslog-ng -Fevd" from a terminal prompt. If syslog-ng isn't starting, it will show you exactly why.

A couple of minor things. You don't need to create the log files themselves; syslog-ng will create them if they don't exist. You don't need to reboot to start syslog-ng--you can do it directly from scribe or a command line (but scribe is much easier).

The five hour thing looks like a time zone thing. Not ringing a bell immediately.

For a log to be listed in uiScribe, you have to run uiScribe again to reset the logs.

Last, if you just want to delete a log message, you don't need to send it to its own file. Just leave out the destination specification. If no destination is specified, syslog-ng deletes it.

 

[Megahurtz]

Thanks for the tip about restarting syslog from scribe. I'm still having trouble getting the message section correct. I'm following the example from the crash filter that has multiple messages using "or" to add to the list, but syslog keeps throwing a syntax error at the closing curly bracket for that section. I tried changing the text string for the messages thinking that may have been part of the problem. Didn't make any difference.

sda:

destination d_sda {
file("/opt/var/log/sda.log");
};

filter f_mymsg {
message("Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE") or
message("Sense Key : Illegal Request [current]") or
message("Add. Sense: Invalid command operation code") or
message("CDB: Write same(16)") or
message("end_request: I/O error, dev sda") or
message("xhci_hcd 0000:00:0c.0: WARN: Stalled endpoint");
};

log {
source(src);
filter(f_mymsg);
destination(d_sda);
flags(final);
};

Here is what I see when trying to restart syslog:

Starting syslog-ng... done.

Restarting uiScribe ...[2020-09-14T03:27:49.690485] WARNING: Duplicate configuration objects (sources, destinations, ...) are not allowed by default starting with syslog-ng 3.3, add "@define allow-config-dups 1" to your configuration to re-enable;

Error parsing config, duplicate filter definition in /opt/etc/syslog-ng.d/sda:12:1-12:2:
7 message("Sense Key : Illegal Request [current]") or
8 message("Add. Sense: Invalid command operation code") or
9 message("CDB: Write same(16)") or
10 message("end_request: I/O error, dev sda") or
11 message("xhci_hcd 0000:00:0c.0: WARN: Stalled endpoint");
12----> };
12----> ^
13
14 log {
15 source(src);
16 filter(f_mymsg);
17 destination(d_sda);

Included from /opt/etc/syslog-ng.conf:12:1-12:1:
7 # Release notes: https://github.com/syslog-ng/syslog-ng/releases
8
9 @version: 3.27
10 #@include "scl.conf" # uncomment this line to for additional functionality, see syslog-ng documentation
11 @include "/opt/etc/syslog-ng.d/" # Put any customization files in this directory
12---->
12----> ^
13 options {
14 chain_hostnames(no); # Enable or disable the chained hostname format.
15 create_dirs(yes);
16 keep_hostname(yes); # Enable or disable hostname rewriting.
17 log_fifo_size(256); # The number of messages that the output queue can store.

syslog-ng documentation: https://www.syslog-ng.com/technical-documents/list/syslog-ng-open-source-edition
contact: https://lists.balabit.hu/mailman/listinfo/syslog-ng
done.
checking syslog-ng daemon ... dead.
the system logger (syslogd) ... is not running!

 

[elorimer]

In one of your other configuration files you have already defined a filter called f_mymsg. It will be one alphabetically earlier than sda. You have it defined in the afpd file you posted earlier.

As a quick fix, change the name of the filter to f_sda in the definition and the log statement.

 

[Megahurtz]

You were right! I had another message filter with the same name in a different file. I've renamed it and now all files process correctly. I think whatever was going on with my kernel time being off sorted itself out too. However, I'm still having a couple of those lines from the logs slipping through my filter.

These two entries:

kernel: sd 0:0:0:0: [sda] Sense Key : Illegal Request [current]
kernel: sd 0:0:0:0: [sda] CDB: Write same(16): 93 08 00 00 00 00 95 ae 9c d8 00 00 00 78 0

When I tried just putting "sd 0:0:0:0: [sda]" into a message filter, it didn't catch any of those messages. I broke them down into their individual messages, which captured most of them, but the two above still aren't being filtered to sda.log. For the second entry, the hex value is changing all the time. Here is my message section:

filter f_sdaspam{
message("Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE") or
message("Sense Key : Illegal Request [current]") or
message("Add. Sense: Invalid command operation code") or
message("CDB: Write same(16)") or
message("end_request: I/O error") or
message("xhci_hcd 0000:00:0c.0");
};

How can I add those two to my sda log?