What's new

Scribe Scribe v3.2.8 [2026-Jan-26] - Entware syslog-ng and logrotate installer for Asuswrt-Merlin

That sounds unlikely to me. I think syslog-ng ignores things like that.
Looks like you're right; after removing all references to the Pi syslog-ng/Scribe does still not start.

So I probably have one more issue to investigate now...

EDIT 1: Both `syslog-ng -Fevd` and running syslog-ng in debugging mode using the Scribe Utilities don't show any errors and the executable keeps running, but Scribe keeps reporting that the syslog-ng daemon is dead (also when using "scribe restart") 😢

What else can I do to debug this?

EDIT 2: Scribe "works" when I manually start syslog-ng, but fails when I try to start the service. I think this behavior is weird:
Code:
➜ /opt/etc/init.d/S01syslog-ng start
 Starting syslog-ng... #
admin@router  /opt/etc/init.d
➜ pidof syslog-ng

admin@router  /opt/etc/init.d
➜ syslog-ng

admin@router  /opt/etc/init.d
➜ pidof syslog-ng
7949 7948
 
Last edited:
The minimum of 120 seconds and the maximum of 210 seconds represent the range under which the debug tests were run to find the average "sweet spot" of 150 seconds that would (hopefully) apply to the largest number of router configurations.

Thanks for the explanations!

However, I would not recommend anything less than 120 seconds for the delay. Any value below that would be considered an unsupported setting/configuration, and I will not spend any time debugging or troubleshooting it.

Ok, no problem, I'll leave it alone for now, but had to at least ask ... but sounds like you've played with it enough already!

:D

Thanks again, working great!
 
I have a similar issue on the Pi; starting rsyslog manually works fine, as a service fails.

Probably pure coincidence, but I'm flabbergasted on both platforms. No clue how to fix this...
 
Playing around with this:
Code:
    wildcard_file(base_dir("/opt/var/log")
                  filename_pattern("syslogd.ScribeInitReboot.LOG")
                  recursive(no) max-files(1) follow_freq(1)
                  log_iw_size(1200) log_fetch_limit(1000) 
        keep-timestamp(no)
    flags(syslog-protocol));
You will see I have added keep-timestamp(no). The effect of this is that when the Reboot.LOG is read back in, messages get a time stamp based on the time processed, rather than the dawn-of-time until ntp syncs. That results in approximately (for me) a three minute gap between the last shutdown message and the busybox start message. That looks neater to me, but scrolling up the time of reboot doesn't stand out so clearly in the 1,447 log messages that make up my startup sequence.

If I follow, with this configuration, the Reboot.LOG is read every second (also the default), and a check is made to see if there are any messages after the last message recorded in the /opt/var/syslog-ng.persist file (which is unreadable). Only new messages are processed. My sense is that this also means the boot sequence is only processed on a reboot but not a restart, which would be desirable behavior if true. It strikes me that it might be more efficient to set follow_freq() to something like a million, since the Reboot.LOG won't change. In 4.9 the preferred behavior is to rely on inotify if it is available on our routers. I wonder if it is? The documentation suggests that rather than following a file, it is preferable to use a program() source to cat the file to messages, but that means that the .persist behavior isn't in play, and the startup messages aren't processed by syslog-ng so the timestamp and filtering behavior isn't in play either.

Now if I follow, log_iw_size() is ignored unless flags(flow-control) is specified for the source. Log_fetch_limit() will read 1000 messages from the file in one thread, and then process those in a multiple threads, writing them out to the destinations in one thread. So in my case, the first 1000 messages will be read and processed, and then syslog-ng will go back for the other 447. It is a form of flow control, but during that time, other messages may be processed from other sources. The output buffer is 2048, so we will never lose messages; we don't get more than 20 or so a second from any other source.

If flags(flow-control) is enabled, then the second bite at Reboot.LOG will be limited to 200 messages, unless some of the 1200 messages in the log_iw_size have been processed. So it might be worth playing with reducing the fetch_limit to 100 and seeing what happens, or increasing the log_iw_size and implementing flow control. When I was fooling around with this a few years ago, I added flow control but not any other options (these were introduced in 4.7, I think), so my fetch limit was 10.

In any case, if I clear the messages log and reboot, my messages file records about 50 shut down messages and four or so minutes later picks up with the reboot sequence, missing those that are filtered into other destinations. All have the same timestamp, so I can't tell what of those messages (if any) are the product of sources other than the Reboot.LOG while it is being processed. But still, a great improvement in scribe, I think.
 
What else can I do to debug this?
This is somewhat of a shot in the dark, but in S01 does the export of the timezone look ok? Do you have ipv6 enabled?
 
No difficulty here with 3.2.9 develop on 102.6 or 388.11. Must have been the reboot that fixed it.
 
Why is updating Scribe considered useless when syslog-ng is not running? (Feels weird to me)
Well, according to the original code written by @cmkelley, updates are not allowed when in that state. Frankly, I don't know the exact reason(s) for it. The original code has a very explicit check for syslog-ng running before any script update is allowed to start, so I can only assume @cmkelley wrote it that way for some valid reason(s) that I'm not aware of, and at this point, I don't have a clear, strong reason to change that behavior.
 
Playing around with this:
Code:
    wildcard_file(base_dir("/opt/var/log")
                  filename_pattern("syslogd.ScribeInitReboot.LOG")
                  recursive(no) max-files(1) follow_freq(1)
                  log_iw_size(1200) log_fetch_limit(1000)
        keep-timestamp(no)
    flags(syslog-protocol));
You will see I have added keep-timestamp(no). The effect of this is that when the Reboot.LOG is read back in, messages get a time stamp based on the time processed, rather than the dawn-of-time until ntp syncs. That results in approximately (for me) a three minute gap between the last shutdown message and the busybox start message. That looks neater to me, but scrolling up the time of reboot doesn't stand out so clearly in the 1,447 log messages that make up my startup sequence.

If I follow, with this configuration, the Reboot.LOG is read every second (also the default), and a check is made to see if there are any messages after the last message recorded in the /opt/var/syslog-ng.persist file (which is unreadable). Only new messages are processed. My sense is that this also means the boot sequence is only processed on a reboot but not a restart, which would be desirable behavior if true. It strikes me that it might be more efficient to set follow_freq() to something like a million, since the Reboot.LOG won't change. In 4.9 the preferred behavior is to rely on inotify if it is available on our routers. I wonder if it is? The documentation suggests that rather than following a file, it is preferable to use a program() source to cat the file to messages, but that means that the .persist behavior isn't in play, and the startup messages aren't processed by syslog-ng so the timestamp and filtering behavior isn't in play either.

Now if I follow, log_iw_size() is ignored unless flags(flow-control) is specified for the source. Log_fetch_limit() will read 1000 messages from the file in one thread, and then process those in a multiple threads, writing them out to the destinations in one thread. So in my case, the first 1000 messages will be read and processed, and then syslog-ng will go back for the other 447. It is a form of flow control, but during that time, other messages may be processed from other sources. The output buffer is 2048, so we will never lose messages; we don't get more than 20 or so a second from any other source.

If flags(flow-control) is enabled, then the second bite at Reboot.LOG will be limited to 200 messages, unless some of the 1200 messages in the log_iw_size have been processed. So it might be worth playing with reducing the fetch_limit to 100 and seeing what happens, or increasing the log_iw_size and implementing flow control. When I was fooling around with this a few years ago, I added flow control but not any other options (these were introduced in 4.7, I think), so my fetch limit was 10.

In any case, if I clear the messages log and reboot, my messages file records about 50 shut down messages and four or so minutes later picks up with the reboot sequence, missing those that are filtered into other destinations. All have the same timestamp, so I can't tell what of those messages (if any) are the product of sources other than the Reboot.LOG while it is being processed. But still, a great improvement in scribe, I think.
I don't like changing the original timestamps of the log entries, especially in situations where I'm trying to troubleshoot/debug issues occurring during the reboot sequence. IMO, the "dawn-of-time" timestamps (before NTP is started) make it extremely fast and easy to find when/where any reboot begins.

One can certainly attempt to fine-tune the syslog-ng source options for a specific router model and configuration, but trying to find a set of options that are meant to work for the vast majority of routers can become a time-consuming proposition, and I already spent enough time as it is to arrive at the current settings. Unless the current configuration generates an error or doesn't work at all, I don't plan on spending any more time chasing the "absolutely best" settings that may (or may not) work for everyone.

"Don't let perfection be the enemy of the good."
 
Slightly off topic: (My Bugbear, so to speak)

"Don't let perfection be the enemy of the good."

really means

"Don't let perfection be the enemy of the good enough."

That is why so many people work with systems that not as good as they could be because they were 'good enough' some time ago BUT not any more !!!

Management, of course, argue that they were 'good enough' ... so what has changed ... because we are still making the same 'sprockets' in the same way ???

and so it goes ........

:rolleyes: :)
 
Does anyone know what's happening here?
Code:
15:44:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:44:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:45:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:45:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:46:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:46:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:47:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:47:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:48:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:48:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:49:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:49:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:50:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:50:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:51:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:51:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:52:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:52:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:53:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:53:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:54:40 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:54:40 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
Feb  2 15:55:41 ripshod syslog-ng[10432]: Error resolving hostname with getaddrinfo(); host='192.168.x.y', error='-2', error_str='Name or service not known'
Feb  2 15:55:41 ripshod syslog-ng[10432]: Initiating connection failed, reconnecting; time_reopen='60'
 
Does anyone know what's happening here?
I’ll point out the obvious that 192.168.x.y isn’t a valid IP address. They should all be numbers. 😄

There’s no value in redacting private LAN IPs.

What did you change recently? Does DNS work on the router locally (nslookup of that IP)?

Edit: A00remote may be to blame.
 
I’ll point out the obvious that 192.168.x.y isn’t a valid IP address. They should all be numbers. 😄

There’s no value in redacting private LAN IPs.

What did you change recently? Does DNS work on the router locally (nslookup of that IP)?
I redacted nothing. That's exactly as it appears in the logs.
My main network is 10.0.0.0/27
 
Does anyone know what's happening here?
Yes, I'm guessing you've removed the *OFF* from the network destination in syslog-ng.conf.
 
Yes, I'm guessing you've removed the *OFF* from the network destination in syslog-ng.conf.
But that's it. I changed nothing. All I did was reboot.
I'll have to look at the settings, I do use a remote syslog server at 10.0.0.15 - that should not have changed in the settings though(?).

*edit*
That was exactly the problem. It's been running fine and logging to the server. When I checked the config the syslog server was still enabled but the address defaulted. 😳
 
Last edited:
Still larking about with the Reboot.LOG:

I removed the iw-window() line, on the theory that without flow-control() it wasn't doing anything, and changed the log-fetch-limit() to 100 from 1000. Rebooted, and the upshot was that I recorded (almost?) none of the startup sequence in messages. So the experiment of seeing syslog-ng go back 14 times to read Reboot.LOG was very much a step in the wrong direction.

I changed log-fetch-limit() to 2000, rebooted, and got all of the Reboot.LOG with the same timestamp as the ntp sync. Mixed in with the last 50 or so other messages were other log messages from add-ons, so the combined source of Reboot.LOG and the syslog and klog sockets was being processed in parallel. I think defining Reboot.LOG as its own source and including it in a combined log statement would produce the same result. A downside of either is that all 1,447 startup messages are going through all the filters (I don't have all that many), but the only ones that are being put in separate buckets are about 30 hostapd messages and one syslog-ng message ("starting up").

Just realized why it is Reboot.LOG and not reboot.log. :)
 

Support SNBForums w/ Amazon

If you'd like to support SNBForums, just use this link and buy anything on Amazon. Thanks!

Sign Up For SNBForums Daily Digest

Get an update of what's new every day delivered to your mailbox. Sign up here!
Back
Top