Scribe scribe - syslog-ng and logrotate installer

[amoney]

I'm guessing RT-AC88U-BC40 is an AiMesh node and you're directing its logs to your main router? The problem is that for some reason, the program name gets changed from "wlceventd" to "syslog". It appears to only happen to the wlceventd log entries, I've no idea why. I've been accumulating a few bits here and there, including this, probably time to push them out. In the meantime, you can change the filter to:

filter f_wlceventd {
    ( program("WLCEVENTD") or
    program("wlceventd") ) and
    ( message("ssoc") or
    message("uth") ) or
    ( program("syslog") and
    message("wlceventd") );
};

in either your AiMesh node or your main router. If you change it on you AiMesh node, the wlceventd messages won't get passed to the main router at all, they'll stay on the AiMesh node router.

Thanks. In this case RT-AC88U is the main router. RT-AC68U is model of the airmesh node. I did not do any setup to push the logs from airmesh to the main node. Will make the update and see if new events get logged there.

 

[amoney]

No, it doesn't pick up pre-defined defaults, BUT some logs that live there shouldn't be touched by logrotate, particularly any skynet logs (skynet-0, skynet.log, & skynet_events.log).

In general, if you write your own syslog-ng filter, there needs to be a corresponding logrotate config. Any you copy from /opt/share/syslog-ng.d/examples should have a corresponding logrotate config in /opt/share/logrotate/examples, and it should be copied to /opt/etc/logrotate.d when you copy the syslog filter.

Ah i assume thats why errormsg does not have a log rotate example. When i saw that i assumed may be we had defaults. Will add for filters i create.

 

[cmkelley]

Ah i assume thats why errormsg does not have a log rotate example. When i saw that i assumed may be we had defaults. Will add for filters i create.

errormsg doesn't have a logrotate config because it's kind of a special case, errormsg is a log that should always be blank. If it has entries, there is a problem that needs to be fixed. I dunno, maybe I should have created one for that. There's also no logrotate for expandlog because that grows VERY quickly and should only be used for debugging purposes. It will grow fast enough to grind the webui to a halt (assuming you're using uiScribe) from the sheer size of the logfile.

 

[amoney]

Yup just started using amtm yesterday and setup scribe and uiScribe. Good to know about the error log. Will keep an extra eye out for that one.

 

[cmkelley]

Thanks. In this case RT-AC88U is the main router. RT-AC68U is model of the airmesh node. I did not do any setup to push the logs from airmesh to the main node. Will make the update and see if new events get logged there.

Huh, that's weird. My AC86U that is my main router is not doing that, it's leaving wlceventd as the program. If you didn't set it up to send logs to the main node, then I don't think it will on its own.

Also, I just looked, I pushed the change that I showed above back in December (I had forgot, just now though to look at the githup rep). When you updated to 2.4.2 (or even 2.4.1) you must not have elected to update the wlceventd filter. If you use uf from the scribe menu to update the filters, and accept the change to wlceventd then it will update to the above.

 

[amoney]

Huh, that's weird. My AC86U that is my main router is not doing that, it's leaving wlceventd as the program. If you didn't set it up to send logs to the main node, then I don't think it will on its own.

Also, I just looked, I pushed the change that I showed above back in December (I had forgot, just now though to look at the githup rep). When you updated to 2.4.2 (or even 2.4.1) you must not have elected to update the wlceventd filter. If you use uf from the scribe menu to update the filters, and accept the change to wlceventd then it will update to the above.

This is interesting. I installed this module yesterday evenining so have not even had to update it yet. I made the changes in the filter and it is now sending the events to the correct log file.

I issued the uf and it never prompted me for updating the wlceventd file probably because i had already made the changes. Weird that my fresh install did not have the updated configs. I assume these configs are downloaded when scribe is installed and not when amtm was setup.

 

[cmkelley]

This is interesting. I installed this module yesterday evenining so have not even had to update it yet. I made the changes in the filter and it is now sending the events to the correct log file.

I issued the uf and it never prompted me for updating the wlceventd file probably because i had already made the changes. Weird that my fresh install did not have the updated configs. I assume these configs are downloaded when scribe is installed and not when amtm was setup.

Okay, that is really weird. Like, I have no clue how that could possibly be weird. The last update to that file was December 18th (https://github.com/cynicastic/scribe/blob/master/syslog-ng.share/wlceventd), which was before 2.4.1 was released. I'm not even going to try to figure it out.

 

[amoney]

Okay, that is really weird. Like, I have no clue how that could possibly be weird. The last update to that file was December 18th (https://github.com/cynicastic/scribe/blob/master/syslog-ng.share/wlceventd), which was before 2.4.1 was released. I'm not even going to try to figure it out.

Lets blame it on some weird caching and call it a night . Thanks for all your help.

 

[cmkelley]

Lets blame it on some weird caching and call it a night . Thanks for all your help.

LOL, couldn't let it go. Found it, I was looking in the wrong place. Proved the old adage that if something exists in two places, it will be wrong in one of them. In this case the version in /opt/share/syslog-ng/examples was correct, but the one that is initially installed in /opt/etc/syslog-ng.d wasn't. So only someone newly installing it would have that problem.

 

[amoney]

LOL, couldn't let it go. Found it, I was looking in the wrong place. Proved the old adage that if something exists in two places, it will be wrong in one of them. In this case the version in /opt/share/syslog-ng/examples was correct, but the one that is initially installed in /opt/etc/syslog-ng.d wasn't. So only someone newly installing it would have that problem.

haha would have driven me crazy until i got to the bottom of this too . I did a quick md5sum check and all other files match.

 

[Stephen Harrington]

haha would have driven me crazy until i got to the bottom of this too . I did a quick md5sum check and all other files match.

@cmkelley, not sure how contributions are collected but feel free to add these to your next Filter Examples update if you feel so inclined.

I run mostly Macs here and was getting lots of annoying "miniupnpd" messages in my RT-AC86U logs very 15 minutes due to bugs in the Mac implementation of mDNSREsponder/Bonjour.

This thread explains the issue, no fix in sight from Apple after a couple of years.

https://www.snbforums.com/threads/r...add-mapping-tcp-error-every-15-minutes.61463/

I've made a Scribe "pair" to filter out the miniupnpd messages to their own log.
Seems to work ok so far - famous last words
Suggestions or fixes gratefully received!

Code below:-

/opt/etc/syslog-ng.d/miniupnpd

# log all miniupnpd logs into one file - /opt/var/log/miniupnpd.log and stop processing miniupnpd logs

destination d_miniupnpd {
    file("/opt/var/log/miniupnpd.log");
};

filter f_miniupnpd {
    program("miniupnpd");
};

log {
    source(src);
    filter(f_miniupnpd);
    destination(d_miniupnpd);
    flags(final);
};

#eof

/opt/etc/logrotate.d/miniupnpd

/opt/var/log/miniupnpd.log {
    minsize 1024k
    daily
    rotate 9
    postrotate
        /usr/bin/killall -HUP syslog-ng
    endscript
}

 

[JT Strickland]

My crash log don't have any entries since May 13. I thought that was good? since that was about the time I changed some of the scripts to store logs, etc, in the usb drive.
Then I reviewed my disk check log and it doesn't have any post May 13 entries either, so I restarted syslog-ng in scribe, but is this something I should periodically check on and do? I think I don't have something right here.
tia,
jts

BTW, that didn't seem to do it. FWIW, every day there's an entry in the syslog-ng.sys.log that states:
May 22 00:05:01 RT-AC86U-8F38 syslog-ng[25231]: The current log file has a mismatching size/inode information, restarting from the beginning; state='affile_sd_curpos(/var/lib/logrotate.status)', stored_inode='20346915', cur_file_inode='22947038', stored_size='245', cur_file_size='245', raw_stream_pos='0'

RT-AC86U w/ 384.17, RT-AC68U Aimesh node w/ same, 250/10 cable w/ Netgear CM-1000, Diversion, UiDivstats, Skynet, AiProtection, DoT, Scribe, UiScribe, Connmon, SpdMerlin, ScMerlin, Nsrum, NtpMerlin

 

[cmkelley]

My crash log don't have any entries since May 13. I thought that was good? since that was about the time I changed some of the scripts to store logs, etc, in the usb drive.
Then I reviewed my disk check log and it doesn't have any post May 13 entries either, so I restarted syslog-ng in scribe, but is this something I should periodically check on and do? I think I don't have something right here.
tia,
jts

There seems to be a correlation between some of the Trend Micro stuff and the dcd_tainted crashes. I haven't had any since May 11th. Not sure what I changed then.

The disk check log is not related to scribe, however, the disk check script only runs when the router reboots, so if you haven't rebooted since the 13th, there won't be any entries after that.

BTW, that didn't seem to do it. FWIW, every day there's an entry in the syslog-ng.sys.log that states:
May 22 00:05:01 RT-AC86U-8F38 syslog-ng[25231]: The current log file has a mismatching size/inode information, restarting from the beginning; state='affile_sd_curpos(/var/lib/logrotate.status)', stored_inode='20346915', cur_file_inode='22947038', stored_size='245', cur_file_size='245', raw_stream_pos='0'

RT-AC86U w/ 384.17, RT-AC68U Aimesh node w/ same, 250/10 cable w/ Netgear CM-1000, Diversion, UiDivstats, Skynet, AiProtection, DoT, Scribe, UiScribe, Connmon, SpdMerlin, ScMerlin, Nsrum, NtpMerlin

There probably isn't a /var/lib/logrotate.status file, and syslog-ng is just annoyed it can't find the file.

 

[JT Strickland]

There seems to be a correlation between some of the Trend Micro stuff and the dcd_tainted crashes. I haven't had any since May 11th. Not sure what I changed then.

The disk check log is not related to scribe, however, the disk check script only runs when the router reboots, so if you haven't rebooted since the 13th, there won't be any entries after that.

There probably isn't a /var/lib/logrotate.status file, and syslog-ng is just annoyed it can't find the file.

Thank you sir. I didn't think there was a relationship between the disk check utility and scribe, but since they both quit the same day, I thought they were kin somehow.
I feel better that maybe I don't have something out of kilter that is causing it. I have rebooted since then, several times no doubt, but I will seek some help regarding that after I search a little more.
thanks again,
jts

Edit: Apparently I was mistaken about rebooting. I deleted the log, rebooted, and now I have a clean entry. Apparently it was crashing about every day or so before May 13 and then stopped about the same time as the log entries.

 

[JT Strickland]

Thank you sir. I didn't think there was a relationship between the disk check utility and scribe, but since they both quit the same day, I thought they were kin somehow.
I feel better that maybe I don't have something out of kilter that is causing it. I have rebooted since then, several times no doubt, but I will seek some help regarding that after I search a little more.
thanks again,
jts

Edit: Apparently I was mistaken about rebooting. I deleted the log, rebooted, and now I have a clean entry. Apparently it was crashing about every day or so before May 13 and then stopped about the same time as the log entries.

Excuse me for answering my own post, but Friday night at 22:05 my crashes returned, after being absent from the crash log for 9 days. It hasn't appeared to adversely affect anything, but puzzles me how it can turn on and off like a faucet. Another possibility is it wasn't being logged for that time period? Just a little head scratcher for me.
Thanks again for the help,
jts

RT-AC86U w/ 384.17, RT-AC68U Aimesh node w/ same, 250/10 cable w/ Netgear CM-1000, Diversion, UiDivstats, Skynet, AiProtection, DoT, Scribe, UiScribe, Connmon, SpdMerlin, ScMerlin, Nsrum, NtpMerlin

 

[archiel]

I installed scribe and uiscribe over the weekend after first getting Skynet configured (and about 10 minutes ago found the post above on wlceventd and updated). I think this is a wonderful tool to focus on relevant activity, but was surprised by the jump in memory use. Using top I could see 298m (33% VSZ), the next largest process is pixelserv-tls, typically ~60k (7%).

While checking to see if editing log_fifo_size in syslog-ng.conf might help, I noted that re-starting scribe, even without any edits to syslog-ng.conf, immediately reduced the memory use by almost 50% and that the change seems to be persistent until a reboot.

Has anyone else seen this behaviour and if I want to delay the start of scribe, to allow other programs to settle down (after a reboot), how would I do this?

 

[elorimer]

Yes, it is unclear why syslog-ng uses so much memory in the HND routers (if that is indeed a true statement). For my 86U, up 23 days now, syslog-ng is reported by htop to be using 165M (but oddly, only 1.2% of memory). Unbound is reported to be using 72K or 5.3% of memory. This just doesn't add up. My pixelserv is reported to be at 55K or 1.6% (which is about right). Others are also wrong: httpd is using around 26K and reported to be 1.0%; dcd is using 23K and reported to be .1% of memory while mastiff is 11K and .2% of memory.

On the other hand, if I use top, syslog-ng is 165M and 38.4% and unbound is 76K or 17.2%. So I think this is some weirdness about how the utilities are firuginr out memory usage rather than something to worry about.

The log_fifo_size cannot make any measurable difference in the memory usage with the number of destinations we have. Also, syslog-ng will restart hourly if skynet is installed, and nightly when logrotate runs.

 

[cmkelley]

Yes, it is unclear why syslog-ng uses so much memory in the HND routers (if that is indeed a true statement). For my 86U, up 23 days now, syslog-ng is reported by htop to be using 165M (but oddly, only 1.2% of memory). Unbound is reported to be using 72K or 5.3% of memory. This just doesn't add up. My pixelserv is reported to be at 55K or 1.6% (which is about right). Others are also wrong: httpd is using around 26K and reported to be 1.0%; dcd is using 23K and reported to be .1% of memory while mastiff is 11K and .2% of memory.

On the other hand, if I use top, syslog-ng is 165M and 38.4% and unbound is 76K or 17.2%. So I think this is some weirdness about how the utilities are firuginr out memory usage rather than something to worry about.

The log_fifo_size cannot make any measurable difference in the memory usage with the number of destinations we have. Also, syslog-ng will restart hourly if skynet is installed, and nightly when logrotate runs.

PDOOMA (Pulled Directly Out Of My A**), I'm gonna guess the raw memory number is the total amount, including whatever is swapped out, and the % is how much of the actual memory in the router it is using. But, PDOOMA, so I could easily be completely wrong.

 

[Ayitaka]

In the meantime, you can change the filter to:

filter f_wlceventd {
    ( program("WLCEVENTD") or
    program("wlceventd") ) and
    ( message("ssoc") or
    message("uth") ) or
    ( program("syslog") and
    message("wlceventd") );
};

in either your AiMesh node or your main router. If you change it on you AiMesh node, the wlceventd messages won't get passed to the main router at all, they'll stay on the AiMesh node router.

I think that code segment is missing another set of ( ) around the first "program" and the "uth" message. To get it to work on my RT AC5300 (no AiMesh) I had to use:

filter f_wlceventd {
    ( ( program("WLCEVENTD") or
    program("wlceventd") ) and
    ( message("ssoc") or
    message("uth") ) ) or
    ( program("syslog") and
    message("wlceventd") );
};

 

[elorimer]

filter f_wlceventd { ( ( program("WLCEVENTD") or program("wlceventd") ) and ( message("ssoc") or message("uth") ) ) or ( program("syslog") and message("wlceventd") ); };

Personally, I think complicated expressions like this could benefit from being simplified by using multiple filters:

filter f_wlceventd1 {
((program("wlceventd" flags(ignore-case) ) and (message("ssoc") or message ("uth"))
};
filter f_wlceventd2 {
(program("syslog") and message("wlceventd") );
};

and then having the log statement OR the filters. AND is the default for multiple filters.