Scribe scribe - syslog-ng and logrotate installer
- Thread starter cmkelley
- Start date
0.9.1:
1. I think we ended up in the wrong place on the source for kernel messaging. We can kill klogd, and it won't read /proc/kmsg or send kernel messages to the system log. Then it falls to syslog-ng to do the job, either by reading /proc/kmsg as a file, or by using system() as a source. Or, we can keep klogd running, sending its messages to /dev/log where it gets picked up by unix-dgram as the source, but keep syslog-ng from reading /proc/kmsg natively. Where we've ended up is killing klogd, but not reading /proc/kmsg natively either as a separate source or by using system().
2. In the new logrotate file, in addition to @Cam's comment, "togetheer".
3. As a future suggestion, if check-status reports syslog-ng is dead, I think it might print a message like: "If syslog-ng fails to start, run 'syslog-ng -d' or 'syslog-ng -Fevd' to see why it is failing".
4. I found the comments you've added in syslog-ng.conf very helpful.
After fixing #1 by changing to system(), things seem to be working just peachy. Great progress!
1. I think we ended up in the wrong place on the source for kernel messaging. We can kill klogd, and it won't read /proc/kmsg or send kernel messages to the system log. Then it falls to syslog-ng to do the job, either by reading /proc/kmsg as a file, or by using system() as a source. Or, we can keep klogd running, sending its messages to /dev/log where it gets picked up by unix-dgram as the source, but keep syslog-ng from reading /proc/kmsg natively. Where we've ended up is killing klogd, but not reading /proc/kmsg natively either as a separate source or by using system().
2. In the new logrotate file, in addition to @Cam's comment, "togetheer".
3. As a future suggestion, if check-status reports syslog-ng is dead, I think it might print a message like: "If syslog-ng fails to start, run 'syslog-ng -d' or 'syslog-ng -Fevd' to see why it is failing".
4. I found the comments you've added in syslog-ng.conf very helpful.
After fixing #1 by changing to system(), things seem to be working just peachy. Great progress!
cmkelley
Very Senior Member
Re item 1 - Oh FFS, I can't believe I did that. Oh, no, wait. That other thing. Yeah, I can totally believe it. :-( I updated my primary router to read system() as a test ... and forgot to update the "master" on my router to push to GitHub. In my (partial) defense my wife and I painted a changing table for our granddaughter this weekend as well, so my attention was rather divided.
Re item 3 - That's on the post - 1.0 todo list.
As an aside, I've only learned enough of git to use the Git Desktop under windows, so I know I'm not using it properly. For syslog-ng.conf in particular, I don't use the exact version on GitHub on my primary router (where I do all my work), mine is edited to also send the logs to my NAS. So I have a folder on my router structured like it is on GitHub. So particularly for that file, I have to remember to make the changes in 2 places. The root of this problem is that this is the only use I have for git, so my motivation to learn it better is poor.
cmkelley
Very Senior Member
Updated: syslog-ng.conf: Added system() to src, remove unix-dgram since we are actively killing klogd and syslogd
syslog-ng.d/logrotate: correct spelling of log file, you'll have to rename the log file manually from logroate.log to logrotate.log. Sorry.
No update to scribe, so no version number bump - that would only update the script anyways.
To update, scribe install and force re-installation of syslog-ng, no need to force re-installation of logrotate or scribe. Note that your syslog-ng.conf file will be renamed to syslog-ng.conf-prev so if you made any changes you can diff the files to see what changed.
syslog-ng.d/logrotate: correct spelling of log file, you'll have to rename the log file manually from logroate.log to logrotate.log. Sorry.
No update to scribe, so no version number bump - that would only update the script anyways.
To update, scribe install and force re-installation of syslog-ng, no need to force re-installation of logrotate or scribe. Note that your syslog-ng.conf file will be renamed to syslog-ng.conf-prev so if you made any changes you can diff the files to see what changed.
joe scian
Very Senior Member
Hi cmkelley -My syslog-ng daemon is dead from status command - running on AC-5300 latest Merlin 384 10.2. Seems to have happened after copying all examples directly to /opt/etc/syslog-ng.d/ and /opt/etc/logrotate.d/ for use.
BTW I followed this procedure as well - To update, scribe install and force re-installation of syslog-ng, I also did a force re-installation of logrotate and scribe. I still have "syslog-ng daemon is dead"
How do I fault find ?
Last edited:
cmkelley
Very Senior Member
First guess, if you just copied everything from /opt/share/syslog-ng/examples, you now have a file in /opt/etc/syslog-ng.d/ named syslog-ng.conf-scribe and probably one named syslog-ng.conf-opkg. Delete both of those from /opt/etc/syslog-ng.d/ and try scribe restart.
It won't cause an error, but if you're running skynet you should delete the firewall file in that directory, and if you're not, you should delete the skynet file. You'll have to scribe restart after doing that (you can do that at the same time you remove the above files)
Beyond that, I've got to get up way too early in the morning, and I'll be gone all day tomorrow. If the above doesn't fix it, try running scribe config and see what it tells you. The folks around here are super helpful.
It won't cause an error, but if you're running skynet you should delete the firewall file in that directory, and if you're not, you should delete the skynet file. You'll have to scribe restart after doing that (you can do that at the same time you remove the above files)
Beyond that, I've got to get up way too early in the morning, and I'll be gone all day tomorrow. If the above doesn't fix it, try running scribe config and see what it tells you. The folks around here are super helpful.
Butterfly Bones
Very Senior Member
Run this in a terminal.
Code:
syslog-ng -Fevd
joe scian
Very Senior Member
that did it -all fixed thanks
joe scian
Very Senior Member
Run this in a terminal.
It will show you what and where it fails. Full credit for this to elorimer and Martineau. It has been invaluable for me since the start of this adventure.Code:syslog-ng -Fevd
after running that command i get these entries at bottom:-
Code:
2019-04-16T04:51:33.295819] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:34.305798] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:35.305801] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:36.305805] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:37.315799] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:38.315820] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:39.325794] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:40.325826] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:41.335800] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:42.335855] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:43.345797] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:44.345827] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:45.355813] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:46.365798] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:47.365839] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:48.375795] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:49.375800] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:50.385802] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T04:51:51.385834] Follow mode file still does not exist; filename='/var/lib/logrotate.status'everything else working fine
Butterfly Bones
Very Senior Member
Sorry, I have no idea, I have never seen anything like that. One of the more experienced syslog-ng users will probably know what that is when they check in.
As long as it is working for you, I'd let it run, that does not look like a critical issue that keeps syslog-ng from working.
joe scian
Very Senior Member
some more complete error messages below
Code:
2019-04-16T05:31:57.775810] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T05:31:58.785786] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T05:31:59.785802] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T05:32:00.795804] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
Code:
[2019-04-16T05:32:57.525801] Destination timed out, reaping; template='/opt/var/log/skynet-0.log', filename='/opt/var/log/skynet-0.log'
Code:
[2019-04-16T05:32:12.655801] Destination timed out, reaping; template='/opt/var/log/expanded-syslog.log', filename='/opt/var/log/expanded-syslog.log'
[2019-04-16T05:32:12.665836] Destination timed out, reaping; template='/opt/var/log/messages', filename='/opt/var/log/messages'
[2019-04-16T05:32:12.845802] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T05:32:13.855789] Follow mode file still does not exist; filename='/var/lib/logrotate.status'joe scian
Very Senior Member
Hi again
I dont have skynet-0.log file or openvpn.log files in opt/var/log even though I have skynet installed and I just connected a client to my VPN server on router. I originally was getting all chkwan.sh wan monitoring messages sent hourly to messages log and also spdmerlin messages twice hourly - now I dont get those messages logged to opt/var/log/messages
I dont have skynet-0.log file or openvpn.log files in opt/var/log even though I have skynet installed and I just connected a client to my VPN server on router. I originally was getting all chkwan.sh wan monitoring messages sent hourly to messages log and also spdmerlin messages twice hourly - now I dont get those messages logged to opt/var/log/messages
joe scian
Very Senior Member
So this was the only line I had in skynet-0.log after reinstalling.
I had to restart Scribe to get it to update all Blocked entries. The openvpn.log file has not been created after i moved openvpn from examples to opt/etc/syslog-ng.d/. After connecting to my OpenVPN server I cannot see any ovpn-server1 entries in messages as well. And no openvpn.log file in opt/var/log
still getting these error messages:-
Code:
- Apr 16 15:00:08 RT-AC5300 Skynet[13782]: [#] 146106 IPs (+0) -- 1760 Ranges Banned (+0) || 119 Inbound -- 0 Outbound Connections Blocked! [save] [7s]still getting these error messages:-
Code:
a TAGS=.source.src#\x0a FACILITY=kern#\x0a FACILITY_NUM=0#\x0a LEVEL=warning#\x0a LEVEL_NUM=4#\x0a PRI=4#\x0a PRIORITY=warning#\x0a FULLHOST=RT-AC5300#\x0a FULLHOST_FROM=RT-AC5300#\x0a HOST=RT-AC5300#\x0a HOST_FROM=RT-AC5300#\x0a LOGHOST=RT-AC5300.#\x0a MSGHDR=kernel: #\x0a MSGID=#\x0a MSGONLY=REJECT IN=br0 OUT=wl0.1 SRC=192.168.2.245 DST=192.168.3.186 LEN=60 TOS=0x00 PREC=0x00 TTL=63 ID=18564 DF PROTO=TCP SPT=35196 DPT=55443 SEQ=3826383029 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A0345B0310000000001030306) #\x0a MSG=REJECT IN=br0 OUT=wl0.1 SRC=192.168.2.245 DST=192.168.3.186 LEN=60 TOS=0x00 PREC=0x00 TTL=63 ID=18564 DF PROTO=TCP SPT=35196 DPT=55443 SEQ=3826383029 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A0345B0310000000001030306) #\x0a MESSAGE=REJECT IN=br0 OUT=wl0.1 SRC=192.168.2.245 DST=192.168.3.186 LEN=60 TOS=0x00 PREC=0x00 TTL=63 ID=18564 DF PROTO=TCP SPT=35196'
[2019-04-16T10:06:35.000452] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:36.010407] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:37.020356] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:38.020386] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:39.030355] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:40.030363] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:41.030366] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:42.040368] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:19.921171] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:20.930385] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:21.940371] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2[2019-04-16T10:06:43.050388] Follow mode file still does not exist; filename='/var/lib/logrotate.status'
[2019-04-16T10:06:43.393541] Incoming log entry; line='PROTO=TCP SPT=53114 DPT=55443 SEQ=3661446808 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A162623620000000001030306) '
[2019-04-16T10:06:43.394087] Outgoing message; message='Apr 16 10:06:43 RT-AC5300 kernel: PROTO=TCP SPT=53114 DPT=55443 SEQ=3661446808 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A162623620000000001030306) \x0a'
[2019-04-16T10:06:43.394355] Outgoing message; message='================================================\x0a PROGRAM=kernel#\x0a PID=#\x0a BSDTAG=5A#\x0a TAG=05#\x0a TAGS=.source.src#\x0a FACILITY=kern#\x0a FACILITY_NUM=0#\x0a LEVEL=notice#\x0a LEVEL_NUM=5#\x0a PRI=5#\x0a PRIORITY=notice#\x0a FULLHOST=RT-AC5300#\x0a FULLHOST_FROM=RT-AC5300#\x0a HOST=RT-AC5300#\x0a HOST_FROM=RT-AC5300#\x0a LOGHOST=RT-AC5300.#\x0a MSGHDR=kernel: #\x0a MSGID=#\x0a MSGONLY=PROTO=TCP SPT=53114 DPT=55443 SEQ=3661446808 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A162623620000000001030306) #\x0a MSG=PROTO=TCP SPT=53114 DPT=55443 SEQ=3661446808 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A162623620000000001030306) #\x0a MESSAGE=PROTO=TCP SPT=53114 DPT=55443 SEQ=3661446808 ACK=0 WINDOW=65535 RES=0x00 SYN URGP=0 OPT (020405B40402080A162623620000000001030306) #\x0a SOURCE=src#\x0a SOURCEIP=127.0.0.1#\x0a SOURCE_IP=#\x0a SEQNUM=6#\x0a UNIXTIME=1555409203#\x0a FULLDAT
Last edited:
We haven't seen this error before. Are you using the scribe script downloaded in the last several hours? There were two typos in it earlier.
Also, when you run syslog-ng -Fevd you will be getting a current log output, not just syslog-ng. Breaking this down into pieces:
1. The "Follow mode" notice is saying that something (but it should be logrotate) is trying to write the logrotate.status file and can't. It has a timer that tries again every minute. My file gets written when the logrotate chron job runs at midnite and is just a list of the logs to be rotated. It is possible this is related to one of the typos.
2. The "reaping" message you got earlier is normal. syslog-ng keeps a destination file open for a bit to see if there are more messages. When the timer rings, it closes the file and recovers the space. This is the "verbose" part of -Fevd.
3. The incoming/outgoing messages that have "PROTO=TCP" represent garbling and is a sign that klogd is still running. It is part of an iptables log entry running through the kernel log system. Try running in terminal "pidof klogd" and see if you get a number. If so we have to figure out why your klogd isn't getting killed.
Also, when you run syslog-ng -Fevd you will be getting a current log output, not just syslog-ng. Breaking this down into pieces:
1. The "Follow mode" notice is saying that something (but it should be logrotate) is trying to write the logrotate.status file and can't. It has a timer that tries again every minute. My file gets written when the logrotate chron job runs at midnite and is just a list of the logs to be rotated. It is possible this is related to one of the typos.
2. The "reaping" message you got earlier is normal. syslog-ng keeps a destination file open for a bit to see if there are more messages. When the timer rings, it closes the file and recovers the space. This is the "verbose" part of -Fevd.
3. The incoming/outgoing messages that have "PROTO=TCP" represent garbling and is a sign that klogd is still running. It is part of an iptables log entry running through the kernel log system. Try running in terminal "pidof klogd" and see if you get a number. If so we have to figure out why your klogd isn't getting killed.
Butterfly Bones
Very Senior Member
This issue with Skynet logging has been driving me bonkers since first install. I miss most hourly logs even in the /mnt/SNB/skynet/events.log. The "DROP IN" messages show in Skynet-0.log show correctly.
Here is the hourly reports (skynet menu 13, 2, 6. 3) the first are with scribe / syslog-ng, the later are without syslog-ng, note 7 hours missing. Like joe, they only seem to show if I manually run them in the Skynet menu.
Code:
Apr 15 08:00:03 RT-AC86U-4608 Skynet: [#] 139383 IPs (+0) -- 1710 Ranges Banned (+0) || 151 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr 15 15:00:03 RT-AC86U-4608 Skynet: [#] 139383 IPs (+0) -- 1710 Ranges Banned (+0) || 384 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr 15 11:00:03 Skynet: [#] 139383 IPs (+0) -- 1710 Ranges Banned (+0) || 40 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr 15 12:00:03 Skynet: [#] 139383 IPs (+0) -- 1710 Ranges Banned (+0) || 227 Inbound -- 0 Outbound Connections Blocked! [save] [3s]
Apr 15 13:00:03 Skynet: [#] 139383 IPs (+0) -- 1710 Ranges Banned (+0) || 1363 Inbound -- 0 Outbound Connections Blocked! [save] [3s]I just need to monitor firewall probes for now using Skynet, I'm seeing upwards of 50 probes per second at times. I'm not comfortable without watching closely for now.
With apologies, @Butterfly Bones, I haven't really been focused on your skynet issues while we were sorting out the garbling. I certainly had some of your issues. I don't pretend to have this figured out, because the firewall script is pretty dense. But I think there are some clues.
1. The hourly output is a cron job of "firewall save". Save is pretty simple. It just runs the Purge_Log function and the Save_IPsets function. When scribe sets the syslog location to /opt/var/log/skynet-0, skynet runs the Purge_Log function on that file. I think that is supposed to strip out all of the skynet messages, including both the BLOCKED messages and what you are seeing as the hourly stats report. If it was working as intended every hour skynet-0 would be emptied completely. But firewall save I don't think runs an hourly stats report itself.
2. Your hourly save runs a lot faster than mine. Mine takes around 14 seconds on my 56U; yours runs in 3 seconds. I wonder whether this has something to do with it.
3. It looks like there is a potential race condition. Syslog-ng is reading the system source, sifting it, and writing these frequent iptables log messages to this skynet-0 log. At the same time, at the top of the hour, skynet is doing a destructive sed on the same file. I think syslog-ng will hold a message if it can't write to the destination, and maybe skynet waits on syslog-ng if it is writing first. But it could be you are not seeing some of those hourly messages because of the accident of when iptables is logging a message at the top of an hour. Dunno.
Still trying to parse where that hourly line comes from, and how the Purge_Logs function does its stuff.
1. The hourly output is a cron job of "firewall save". Save is pretty simple. It just runs the Purge_Log function and the Save_IPsets function. When scribe sets the syslog location to /opt/var/log/skynet-0, skynet runs the Purge_Log function on that file. I think that is supposed to strip out all of the skynet messages, including both the BLOCKED messages and what you are seeing as the hourly stats report. If it was working as intended every hour skynet-0 would be emptied completely. But firewall save I don't think runs an hourly stats report itself.
2. Your hourly save runs a lot faster than mine. Mine takes around 14 seconds on my 56U; yours runs in 3 seconds. I wonder whether this has something to do with it.
3. It looks like there is a potential race condition. Syslog-ng is reading the system source, sifting it, and writing these frequent iptables log messages to this skynet-0 log. At the same time, at the top of the hour, skynet is doing a destructive sed on the same file. I think syslog-ng will hold a message if it can't write to the destination, and maybe skynet waits on syslog-ng if it is writing first. But it could be you are not seeing some of those hourly messages because of the accident of when iptables is logging a message at the top of an hour. Dunno.
Still trying to parse where that hourly line comes from, and how the Purge_Logs function does its stuff.
Butterfly Bones
Very Senior Member
Thanks, but I have no expectations that anyone focus on my Skynet issue. Scribe is beta and that takes priority.
My hourly saves running fast is the RT-AC86U that has been confirmed with Adamm as normal time for this router, yes it is faster. I loose very little download speed with a full time VPN for all clients thanks to dual core (one for router, one for VPN) and AES encryption for the VPN, precisely the reason I bought it.
I do not understand why it works using the Skynet default log location and not the scribe redirect location. What I don't understand is that Skynet writes its own logs (skynet.log & events.log) to /mnt/<USB_name>/skynet/ but when I check those two logs with "cat" they are missing entries as well.
That is why I am going to reinstall scribe and not redirect Skynet logs for now, to see what happens. I'm not sure if or how this will help troubleshoot whatever causes missing hourly reports. That can be pursued later.
Similar threads
Similar threads
Similar threads
-
Scribe Strange Issue with Scribe / Syslog-NG after Reboot
- Started by ScottW
- Replies: 7
-
Scribe Scribe nvram log_path - what should it be?
- Started by vibroverbus
- Replies: 4
-
Scribe Issues with scribe.... Errors all over the place after restarting scribe!
- Started by SomeWhereOverTheRainBow
- Replies: 8
-
Scribe [SOLVED] syslog-ng intermittent failure to shutdown which messes all logging
- Started by Tarek Yag
- Replies: 15
-
AdGuardHome There are tons of dnsproxy error messages occuring on syslog.
- Started by jklim
- Replies: 2
-
Updated scMerlin to 2.5.5 - syslog stops at 'syslogd exiting'
- Started by thecheapseats
- Replies: 9