Scribe scribe - syslog-ng and logrotate installer

Butterfly Bones · Apr 9, 2019

L&LD said:
And that is why you're so far ahead than me!

I have to admit I have installed the scribe script for a few days now, but really, I don't know what to do with it. I fire it up in PuTTY and see the options (I've even tried them all) and I still am stuck.

Do I have to do anything past installing and seeing it is 'alive'?

Add the filter files to clean up your webGUI syslog if you have not. You just linked above to the ones I find useful. The I run "tail -F /opt/var/log/nameof.log to monitor on those I want to check as I play and play and play....

Then do this as posted here by elorimer. That is very cool and very useful as you play with it. Drilling down in it si informative, and it complies and classifies log entries in a different way that I never considered. (thumbs up emoji)

Butterfly Bones · Apr 9, 2019

Aaaaannnnnddddd, we have clues!!

Terminal with "tail -f /opt/var/log/skynet-0.log" at the hour, check this!

"tail: /opt/var/log/skynet-0.log has been replaced; following end of new file"

In between the old log (kernel) at 14:59 it gets one stats from Skynet at 11:40:59, and the last two saves from Skynet at 12:00 and 13:00. Then it jumps back to 15:00 with the new log (kernel).

Code:

Apr  9 14:59:53 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.176.27.90 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=237 ID=24028 PROTO=TCP SPT=40851 DPT=39817 SEQ=4036490170 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
tail: /opt/var/log/skynet-0.log has been replaced; following end of new file
Apr  9 11:40:59 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5243 Inbound -- 0 Outbound Connections Blocked! [stats] [3s]
Apr  9 12:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5269 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 13:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5368 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 15:00:30 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=81.22.45.228 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=242 ID=45912 PROTO=TCP SPT=59741 DPT=33555 SEQ=231409060 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
Apr  9 15:00:37 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=78.108.177.53 DST=71.93.53.239 LEN=48 TOS=0x00 PREC=0x00 TTL=109 ID=6735 DF PROTO=TCP SPT=37088 DPT=8080 SEQ=140259376 ACK=0 WINDOW=8192 RES=0x00 SYN URGP=0 OPT (020405B401010402) MARK=0x8000000

dave14305 · Apr 9, 2019

Butterfly Bones said:

Aaaaannnnnddddd, we have clues!!

Terminal with "tail -f /opt/var/log/skynet-0.log" at the hour, check this!

"tail: /opt/var/log/skynet-0.log has been replaced; following end of new file"

In between the old log (kernel) at 14:59 it gets one stats from Skynet at 11:40:59, and the last two saves from Skynet at 12:00 and 13:00. Then it jumps back to 15:00 with the new log (kernel).

Code:

Apr  9 14:59:53 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.176.27.90 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=237 ID=24028 PROTO=TCP SPT=40851 DPT=39817 SEQ=4036490170 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
tail: /opt/var/log/skynet-0.log has been replaced; following end of new file
Apr  9 11:40:59 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5243 Inbound -- 0 Outbound Connections Blocked! [stats] [3s]
Apr  9 12:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5269 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 13:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5368 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 15:00:30 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=81.22.45.228 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=242 ID=45912 PROTO=TCP SPT=59741 DPT=33555 SEQ=231409060 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
Apr  9 15:00:37 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=78.108.177.53 DST=71.93.53.239 LEN=48 TOS=0x00 PREC=0x00 TTL=109 ID=6735 DF PROTO=TCP SPT=37088 DPT=8080 SEQ=140259376 ACK=0 WINDOW=8192 RES=0x00 SYN URGP=0 OPT (020405B401010402) MARK=0x8000000

What is your syslog location set as in SkyNet? Reads like SkyNet is sed your file on the hour.

Butterfly Bones · Apr 9, 2019

dave14305 said:
What is your syslog location set as in SkyNet? Reads like SkyNet is sed your file on the hour.

Same as the post above.

Code:

/opt/var/log/skynet-0.log

~~So this is the filtered log by syslog-ng from the /tmp/syslog.log symlinked to /opt/var/log/messages.~~

Uh, nope, nevermind, that is directly from Skynet. From the scribe_debug.log

Code:

### Skynet log locations:
syslogloc="/opt/var/log/skynet-0.log"
syslog1loc="/tmp/syslog.log-1"

Butterfly Bones · Apr 9, 2019

Butterfly Bones said:

Aaaaannnnnddddd, we have clues!!

Terminal with "tail -f /opt/var/log/skynet-0.log" at the hour, check this!

"tail: /opt/var/log/skynet-0.log has been replaced; following end of new file"

In between the old log (kernel) at 14:59 it gets one stats from Skynet at 11:40:59, and the last two saves from Skynet at 12:00 and 13:00. Then it jumps back to 15:00 with the new log (kernel).

Code:

Apr  9 14:59:53 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.176.27.90 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=237 ID=24028 PROTO=TCP SPT=40851 DPT=39817 SEQ=4036490170 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
tail: /opt/var/log/skynet-0.log has been replaced; following end of new file
Apr  9 11:40:59 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5243 Inbound -- 0 Outbound Connections Blocked! [stats] [3s]
Apr  9 12:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5269 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 13:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5368 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 15:00:30 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=81.22.45.228 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=242 ID=45912 PROTO=TCP SPT=59741 DPT=33555 SEQ=231409060 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000
Apr  9 15:00:37 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=78.108.177.53 DST=71.93.53.239 LEN=48 TOS=0x00 PREC=0x00 TTL=109 ID=6735 DF PROTO=TCP SPT=37088 DPT=8080 SEQ=140259376 ACK=0 WINDOW=8192 RES=0x00 SYN URGP=0 OPT (020405B401010402) MARK=0x8000000

Here is the another top of the hour log switch and some "interesting" lines.
- "syslog-ng starting up" hmm it seems to have been running....
- "child connection from" and "password auth succeeded" are me opening the FTP connection with FileZilla
- syslog connection established" is sending to Loggly

Code:

Apr  9 16:59:23 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.200.118.46 DST=71.93.53.239 LEN=42 TOS=0x00 PREC=0x00 TTL=239 ID=54321 PROTO=UDP SPT=46168 DPT=443 LEN=22 MARK=0x8000000
tail: /opt/var/log/skynet-0.log has been replaced; following end of new file
Apr  9 11:40:59 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5243 Inbound -- 0 Outbound Connections Blocked! [stats] [3s]
Apr  9 12:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5269 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 13:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5368 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 16:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5691 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 16:18:03 RT-AC86U-4608 Skynet[27023]: syslog-ng starting up; version='3.19.1'
Apr  9 16:18:04 RT-AC86U-4608 Skynet[27023]: Syslog connection established; fd='15', server='AF_INET(52.21.83.61:514)', local='AF_INET(0.0.0.0:0)'
Apr  9 16:18:55 RT-AC86U-4608 Skynet[26957]: Exit (username): Exited normally
Apr  9 16:19:45 RT-AC86U-4608 Skynet[27093]: Child connection from 192.168.1.5:35071
Apr  9 16:19:45 RT-AC86U-4608 Skynet[27093]: Password auth succeeded for 'username' from 192.168.1.X:35071
Apr  9 16:19:52 RT-AC86U-4608 Skynet[27023]: syslog-ng shutting down; version='3.19.1'
Apr  9 17:00:47 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.53.91.50 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=236 ID=60760 PROTO=TCP SPT=49083 DPT=8883 SEQ=1678506500 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000

I see where the syslog-ng shutting down and then starting up is from the syslog-ng log:

Code:

Apr  9 16:18:02 RT-AC86U-4608 syslog-ng[19656]: syslog-ng shutting down; version='3.19.1'
Apr  9 16:19:53 RT-AC86U-4608 syslog-ng[27157]: syslog-ng starting up; version='3.19.1'
Apr  9 16:19:53 RT-AC86U-4608 syslog-ng[27157]: Syslog connection established; fd='15', server='AF_INET(52.10.127.183:514)', local='AF_INET(0.0.0.0:0)'

Why? I have no idea. It looks like some of the filters for syslog-ng are reading from the /opt/var/log/messages and filtering to more than one log (?), even though they all have the "flags(final);" at the end of the filter.

Cam · Apr 9, 2019

Enjoying fiddling with this setup thanks @cmkelley

I was adding the pixelserv logrotate sample to my setup, and noticed the postrotate command is:

Code:

/usr/bin/killall -HUP syslog-ng

Shouldn't the HUP signal be sent to pixelserv to it can follow new log?

Code:

/usr/bin/killall -HUP /opt/bin/pixelserv-tls

cmkelley · Apr 9, 2019

Cam said:
Enjoying fiddling with this setup thanks @cmkelley

I was adding the pixelserv logrotate sample to my setup, and noticed the postrotate command is:

Code:

/usr/bin/killall -HUP syslog-ng

Shouldn't the HUP signal be sent to pixelserv to it can follow new log?

Code:

/usr/bin/killall -HUP /opt/bin/pixelserv-tls

No, because syslog-ng is the program that is writing to the file. pixelserv-tls, openvpn, etc., are just sending messages to the system logging service, they don't know or care what that service is doing with the message.

To avoid unnecessary overhead, syslog-ng keeps the files open, so it is not linked to the filename per se, but to the actual file itself (via a file handle). When logrotate comes along and renames the file, syslog-ng is still linked to that same file, and would happily keep writing to the renamed file (because the file handle doesn't change) instead of creating a new file. Sending syslog-ng the HUP makes it close all its open files and re-open them. So now files that have been renamed will be closed and a new file with the original name will be created and opened. Files that haven't been renamed because the logrotate conditions weren't met will simply be reopened so syslog-ng will continue writing to those files.

If you have a program that writes its own logs (i.e. doesn't use the system logging facility), you'd have to determine if that program keeps the file open or not between writes. The best way to tell is to rename the file while the program is running and see if it keeps writing to the old file or creates a new one. Sometimes the documentation will tell you, particularly if it looks for a different signal than HUP (which, apparently, some do).

To be fair, this one tripped me up initially too.

cmkelley · Apr 9, 2019

Butterfly Bones said:

Here is the another top of the hour log switch and some "interesting" lines.
- "syslog-ng starting up" hmm it seems to have been running....
- "child connection from" and "password auth succeeded" are me opening the FTP connection with FileZilla
- syslog connection established" is sending to Loggly

Code:

Apr  9 16:59:23 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.200.118.46 DST=71.93.53.239 LEN=42 TOS=0x00 PREC=0x00 TTL=239 ID=54321 PROTO=UDP SPT=46168 DPT=443 LEN=22 MARK=0x8000000
tail: /opt/var/log/skynet-0.log has been replaced; following end of new file
Apr  9 11:40:59 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5243 Inbound -- 0 Outbound Connections Blocked! [stats] [3s]
Apr  9 12:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5269 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 13:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5368 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 16:00:03 RT-AC86U-4608 Skynet: [#] 154538 IPs (+0) -- 1634 Ranges Banned (+0) || 5691 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr  9 16:18:03 RT-AC86U-4608 Skynet[27023]: syslog-ng starting up; version='3.19.1'
Apr  9 16:18:04 RT-AC86U-4608 Skynet[27023]: Syslog connection established; fd='15', server='AF_INET(52.21.83.61:514)', local='AF_INET(0.0.0.0:0)'
Apr  9 16:18:55 RT-AC86U-4608 Skynet[26957]: Exit (username): Exited normally
Apr  9 16:19:45 RT-AC86U-4608 Skynet[27093]: Child connection from 192.168.1.5:35071
Apr  9 16:19:45 RT-AC86U-4608 Skynet[27093]: Password auth succeeded for 'username' from 192.168.1.X:35071
Apr  9 16:19:52 RT-AC86U-4608 Skynet[27023]: syslog-ng shutting down; version='3.19.1'
Apr  9 17:00:47 RT-AC86U-4608 kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=88:d7:f6:1d:46:08:00:01:5c:6d:22:46:08:00 SRC=185.53.91.50 DST=71.93.53.239 LEN=40 TOS=0x00 PREC=0x00 TTL=236 ID=60760 PROTO=TCP SPT=49083 DPT=8883 SEQ=1678506500 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x8000000

I see where the syslog-ng shutting down and then starting up is from the syslog-ng log:

Code:

Apr  9 16:18:02 RT-AC86U-4608 syslog-ng[19656]: syslog-ng shutting down; version='3.19.1'
Apr  9 16:19:53 RT-AC86U-4608 syslog-ng[27157]: syslog-ng starting up; version='3.19.1'
Apr  9 16:19:53 RT-AC86U-4608 syslog-ng[27157]: Syslog connection established; fd='15', server='AF_INET(52.10.127.183:514)', local='AF_INET(0.0.0.0:0)'

Why? I have no idea. It looks like some of the filters for syslog-ng are reading from the /opt/var/log/messages and filtering to more than one log (?), even though they all have the "flags(final);" at the end of the filter.

~~syslog-ng will shut down and restart if a log is rotated (see reply to @Cam above), do you have logrotate running more than once a day?~~

Spoke too soon. When logrotate runs and sends HUP to syslog-ng, it logs it as reloading the configuration:

Code:

Apr  8 00:05:00 lion syslog-ng[27758]: Configuration reload request received, reloading configuration;
Apr  8 00:05:00 lion syslog-ng[27758]: Configuration reload finished;

syslog-ng shut down and restarted on my system today too while I wasn't home. Interesting.

Butterfly Bones · Apr 9, 2019

cmkelley said:
syslog-ng will shut down and restart if a log is rotated (see reply to @Cam above), do you have logrotate running more than once a day?

No, though I just had to go look, since I am only using your files from share/examples. I need to get some for logs I have added of mine, or does the A00global handle any logs not explicitly configured? I have not looked closely since the ones I created are very small and could run months before my USB drive space gets tight. On the to do list though.

Cam · Apr 9, 2019

cmkelley said:
No, because syslog-ng is the program that is writing to the file. pixelserv-tls, openvpn, etc., are just sending messages to the system logging service, they don't know or care what that service is doing with the message.

Ahh that makes sense. I was setting up logrotate for nginx and so set that to reload nginx, then spotted pixelserv and jumped the gun a bit I guess

. Thanks.

cmkelley · Apr 9, 2019

Butterfly Bones said:
No, though I just had to go look, since I am only using your files from share/examples. I need to get some for logs I have added of mine, or does the A00global handle any logs not explicitly configured? I have not looked closely since the ones I created are very small and could run months before my USB drive space gets tight. On the to do list though.

See my edit, I was wrong about syslog-ng restarting.

It logs it as reloading the configuration. Also, mine restarted itself today while I was away, I don't know what that's all about.

A00global only sets some switches where I think the defaults are less than optimal, or that aren't clearly defined and I want a certain behavior.. In that sense, it applies to every log file, even messages.

Code:

# global variable overrides from /opt/etc/logrotate.conf

sharedscripts # if multiple logs run the same postrotate script, only run it once

# compress, but not first rotation due to file handling
compress
delaycompress

missingok # no error is log file is missing
notifempty # don't rotate an empty logfile
[/CODE/
sharedscripts means the HUP signal only gets sent to syslog-ng once per run, instead of for every file that asks for that.
compress  compresses the rotated files
delaycompress  means the first rotation isn't compressed. 
missingok keeps logrotate from pitching a fit if the log file it's being asked to rotate doesn't exist.
notifempty keeps logrotate from rotating an empty log if you have it set to rotate on a set schedule rather than by size, or a combination thereof.

Butterfly Bones · Apr 9, 2019

cmkelley said:
See my edit, I was wrong about syslog-ng restarting. It logs it as reloading the configuration. Also, mine restarted itself today while I was away, I don't know what that's all about.

A00global only sets some switches where I think the defaults are less than optimal, or that aren't clearly defined and I want a certain behavior.. In that sense, it applies to every log file, even messages.

Code:

# global variable overrides from /opt/etc/logrotate.conf sharedscripts # if multiple logs run the same postrotate script, only run it once # compress, but not first rotation due to file handling compress delaycompress missingok # no error is log file is missing notifempty # don't rotate an empty logfile [/CODE/ sharedscripts means the HUP signal only gets sent to syslog-ng once per run, instead of for every file that asks for that. compress compresses the rotated files delaycompress means the first rotation isn't compressed. missingok keeps logrotate from pitching a fit if the log file it's being asked to rotate doesn't exist. notifempty keeps logrotate from rotating an empty log if you have it set to rotate on a set schedule rather than by size, or a combination thereof.

I recognize most of those from working on this a year ago, and I still look at my old files for reference, thought what I learned from kvic is much different than the files now, not sure if that is just your way of doing things or if syslog-ng changed that much. Either way, the ones now are much easier for me to follow and understand than the old ones, although I still have a boat load to learn and comprehend.

tomsk · Apr 10, 2019

i noticed in your amendment to rc.func.syslog-ng , you deleted the first letter of PRECMD

Code:

RECMD="kill_syslogd"
# enabling the below can be useful when having problems,
# but fills up the logfile fast
#ARGS="-v"

elorimer · Apr 10, 2019

tomsk said:
you deleted the first letter of PRECMD

Thank you. Driving me nuts trying to figure out what changed. Sometimes it pays to give up and start the next day, when problems magically are solved for you.

cmkelley · Apr 10, 2019

elorimer said:
Thank you. Driving me nuts trying to figure out what changed. Sometimes it pays to give up and start the next day, when problems magically are solved for you.

Great .... and I have no way to fix that from work. I'll be home in about 12 hours ...

FAIL!

cmkelley · Apr 10, 2019

cmkelley said:
Great .... and I have no way to fix that from work. I'll be home in about 12 hours ...

FAIL!

EDIT: OH, hey! I can edit directly on GitHub!

Fixed, although the version number isn't rolled. Which actually doesn't matter much, just updating scribe won't update rc.func.syslog-ng anyways.

If you force updating scribe, then you can do as above, and

Code:

cp /opt/tmp/scribe-master/init.d/rc.func.syslog-ng /opt/etc/init.d  && scribe restart

Sorry .... you can tell I don't code for a living, heck I'd starve to death.

elorimer · Apr 10, 2019

I'm on the trail of a puzzle about the skynet logging. With the customary filter:

Code:

# logs everything from Skynet to /opt/var/log/skynet-0.log
filter f_skynet {
    program("Skynet") or
    message("BLOCKED -") or
    message("DROP IN=");
};

I get this in my skynet-0.log file:

Code:

Apr 10 10:17:26 RT-AC56R kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=185.176.27.242 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=239 ID=56329 PROTO=TCP SPT=59128 DPT=3364 SEQ=741691884 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x81000000
Apr 10 10:19:09 RT-AC56R kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00<4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=185.254.122.20 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=237 ID=28881 <4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=89.248.168.112 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=236 ID=54321 OOTPST401DT50 E=93166AK0WNO=53 E=x0SNUG= <4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08<4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=<4>[BLO.....

You can see that the 10:17:26 message looks properly logged. The next message, at 10:19:09, is a repeating sequence of partial iptables output (I've truncated it above).

At the same time, in my messages file, I am getting this:

Code:

Apr 10 10:17:17 RT-AC56R kernel: :56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=152.171.166.4 DST=96.58.128.193 LEN=40 TOS=0x16 PREC=0x00 TTL=47 ID=40675 PROTO=TCP SPT=15485 DPT=23 SEQ=1614446785 ACK=0 WINDOW=4437 RES=0x00 SYN URGP=0
Apr 10 10:18:39 RT-AC56R kernel: PROTO=TCP SPT=38668 DPT=8000 SEQ=3100892464 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0
Apr 10 10:19:35 RT-AC56R kernel: :90:19:08:00 SRC=107.170.234.219 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=238 ID=54321 PROTO=TCP SPT=44043 DPT=21 SEQ=4103115799 ACK=0 PROTO=TCP SPT=56370 DPT=3438 SEQ=1750090962 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x80800000

These look like fragments as well. Both skynet-0 and messages are filled with these stutterings (my technical term for utterings that are not messages). Anyone else seeing this?

tomsk · Apr 10, 2019

elorimer said:

I'm on the trail of a puzzle about the skynet logging. With the customary filter:

Code:

# logs everything from Skynet to /opt/var/log/skynet-0.log
filter f_skynet {
    program("Skynet") or
    message("BLOCKED -") or
    message("DROP IN=");
};

I get this in my skynet-0.log file:

Code:

Apr 10 10:17:26 RT-AC56R kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=185.176.27.242 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=239 ID=56329 PROTO=TCP SPT=59128 DPT=3364 SEQ=741691884 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x81000000
Apr 10 10:19:09 RT-AC56R kernel: [BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00<4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=185.254.122.20 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=237 ID=28881 <4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=89.248.168.112 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=236 ID=54321 OOTPST401DT50 E=93166AK0WNO=53 E=x0SNUG= <4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=2c:56:dc:54:63:00:00:7e:95:41:90:19:08<4>[BLOCKED - INBOUND] IN=eth0 OUT= MAC=<4>[BLO.....

You can see that the 10:17:26 message looks properly logged. The next message, at 10:19:09, is a repeating sequence of partial iptables output (I've truncated it above).

At the same time, in my messages file, I am getting this:

Code:

Apr 10 10:17:17 RT-AC56R kernel: :56:dc:54:63:00:00:7e:95:41:90:19:08:00 SRC=152.171.166.4 DST=96.58.128.193 LEN=40 TOS=0x16 PREC=0x00 TTL=47 ID=40675 PROTO=TCP SPT=15485 DPT=23 SEQ=1614446785 ACK=0 WINDOW=4437 RES=0x00 SYN URGP=0
Apr 10 10:18:39 RT-AC56R kernel: PROTO=TCP SPT=38668 DPT=8000 SEQ=3100892464 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0
Apr 10 10:19:35 RT-AC56R kernel: :90:19:08:00 SRC=107.170.234.219 DST=96.58.128.193 LEN=40 TOS=0x00 PREC=0x00 TTL=238 ID=54321 PROTO=TCP SPT=44043 DPT=21 SEQ=4103115799 ACK=0 PROTO=TCP SPT=56370 DPT=3438 SEQ=1750090962 ACK=0 WINDOW=1024 RES=0x00 SYN URGP=0 MARK=0x80800000

These look like fragments as well. Both skynet-0 and messages are filled with these stutterings (my technical term for utterings that are not messages). Anyone else seeing this?

Did you try mucking around with the config file to see if its truncated because of msg length?....

Code:

log_fifo_size(256); # The number of messages that the output queue can store.
    log_msg_size(16384); # Maximum length of a message in bytes.

elorimer · Apr 10, 2019

tomsk said:
Did you try mucking around with the config file to see if its truncated because of msg length?....

Yes, I have left it at 16384. I even went back to your posts from 2 years ago in the other thread, where you had it at 1024!

tomsk · Apr 10, 2019

Can we use such a thing as program ("Skynet") ... From what i understand Skynet is script rather than a daemon. The skynet logs are mostly kernel messages from what i can see.

Code:
program: Receiving messages from external applications
source: Read, receive, and collect log messages > program: Receiving messages from external applications
The program driver starts an external application and reads messages from the standard output (stdout) of the application. It is mainly useful to receive log messages from daemons that accept incoming messages and convert them to log messages.

The program driver has a single required parameter, specifying the name of the application to start.

Declaration:
Example: Using the program() driver

Code:

source s_program { program("/etc/init.d/mydaemon"); };

Thread starter	Title	Forum	Replies	Date
S	Scribe Strange Issue with Scribe / Syslog-NG after Reboot	Asuswrt-Merlin AddOns	7	Dec 30, 2023
V	Scribe Scribe nvram log_path - what should it be?	Asuswrt-Merlin AddOns	4	Feb 17, 2024
	Scribe Issues with scribe.... Errors all over the place after restarting scribe!	Asuswrt-Merlin AddOns	8	Dec 7, 2023
	Scribe [SOLVED] syslog-ng intermittent failure to shutdown which messes all logging	Asuswrt-Merlin AddOns	15	Oct 21, 2024
J	AdGuardHome There are tons of dnsproxy error messages occuring on syslog.	Asuswrt-Merlin AddOns	2	Jul 26, 2024
T	Updated scMerlin to 2.5.5 - syslog stops at 'syslogd exiting'	Asuswrt-Merlin AddOns	9	Jun 25, 2024

Scribe scribe - syslog-ng and logrotate installer

Very Senior Member

Very Senior Member

Part of the Furniture

Very Senior Member

Very Senior Member

Regular Contributor

Very Senior Member

Very Senior Member

Very Senior Member

Regular Contributor

Very Senior Member

Very Senior Member

Very Senior Member

Part of the Furniture

Very Senior Member

Very Senior Member

Part of the Furniture

Very Senior Member

Part of the Furniture

Very Senior Member

Similar threads

Similar threads

Support SNBForums w/ Amazon

Sign Up For SNBForums Daily Digest