Scribe scribe - syslog-ng and logrotate installer

[cmkelley]

Hrmmm. Not seeing it on my AC86 on 3.23. I will try to carve out some time this weekend to see what I can figure out. I have to assume you've all at least tried re-booting?

 

[Butterfly Bones]

Another way that looks like it would work is to specify something like the default message format in the skynet config file:

destination d_skynet {
    file("/opt/var/log/skynet-0.log", template("${DATE} ${HOST} ${MSGHDR}${MESSAGE}\n") );
};

This might be a better way for scribe to change the included filter as it would be backwards compatible to 3.19, etc. Anyway, try both.

After the update to amtm with the entware update check, I decided to proceed with the syslog-ng update. All went smooth, and I used the above "template" filter after testing the "time-reap" one. Both worked, but the fact that the "template" one is backward compatible might make it the better choice. Maybe it will stay compatible into the future too, who knows?

edit - This "template" one stops logging on the hour change.

 

[cmkelley]

After the update to amtm with the entware update check, I decided to proceed with the syslog-ng update. All went smooth, and I used the above "template" filter after testing the "time-reap" one. Both worked, but the fact that the "template" one is backward compatible might make it the better choice. Maybe it will stay compatible into the future too, who knows?

Setting a global time_reap(60) (i.e. in /opt/etc/syslog-ng.conf) is backwards compatible though, which is the route I'm taking, it removes the possibility that something else in the future may mysteriously not work with syslog-ng. I think that has the effect of simply reverting to the pre-3.23 behaviour.

I see why One Identity sells support for this thing, they don't seem too concerned about breaking expected behaviour. This change was very poorly documented IMHO. I would have never discovered it given the limited amount of time I have to devote to this. Many thanks to @elorimer for figuring this out.

 

[cmkelley]

Setting a global time_reap(60) (i.e. in /opt/etc/syslog-ng.conf) is backwards compatible though, which is the route I'm taking, it removes the possibility that something else in the future may mysteriously not work with syslog-ng. I think that has the effect of simply reverting to the pre-3.23 behaviour.

I see why One Identity sells support for this thing, they don't seem too concerned about breaking expected behaviour. This change was very poorly documented IMHO. I would have never discovered it given the limited amount of time I have to devote to this. Many thanks to @elorimer for figuring this out.

hrmmmmmm. Setting time_reap(60) as a global variable doesn't provide the expected behaviour. It still stops logging at the hour mark. I guess the next thing is to try changing to (2) like @elorimer did, but that doesn't make sense, it should work the way it did before.

 

[Butterfly Bones]

hrmmmmmm. Setting time_reap(60) as a global variable doesn't provide the expected behaviour. It still stops logging at the hour mark. I guess the next thing is to try changing to (2) like @elorimer did, but that doesn't make sense, it should work the way it did before.

I had the same thing with the "template" filter stopped on the hour.

destination d_skynet {
    file("/opt/var/log/skynet-0.log", template("${DATE} ${HOST} ${MSGHDR}${MESSAGE}\n") );

I then changed back to the "time-reap(2)" one and logging started.

destination d_skynet {
    file("/opt/var/log/skynet-0.log", time-reap(2));
};

I'll check what happens on the upcoming 2100 hour (PDT)

Stopping scribe, changing filter, then using\

syslog-ng -Fevd

shows no errors with either one.

edit - The hour change works as expected with the "time-reap(2)" filter.

Nov  2 21:00:03 RT-AC86U-4608 Skynet: [#] 127741 IPs (+0) -- 27216 Ranges Banned (+0) || 7707 Inbound -- 21 Outbound Connections Blocked! [save] [3s]
Nov  2 21:00:07 RT-AC86U-4608 kernel: [BLOCKED - INBOUND].........
Nov  2 21:00:20 RT-AC86U-4608 kernel: [BLOCKED - INBOUND].........

 

[elorimer]

hrmmmmmm. Setting time_reap(60) as a global variable doesn't provide the expected behaviour. It still stops logging at the hour mark. I guess the next thing is to try changing to (2) like @elorimer did, but that doesn't make sense, it should work the way it did before.

I quite agree with you about the poor documentation of this "new functionality". I also thought the reason for the change was poorly understood. If one is to have a file destination at all, then the change completely breaks the prior behavior if there is any other process that addresses the file. It appears our scenario is an edge case. From https://github.com/syslog-ng/syslog-ng/pull/2798:

The PR also introduces a new functionality: If the pipe() or file() destination's filepath does not have a template, the time-reap() is not inherited from the global options, but is disabled, by default. The user can override this by explicitly setting time-reap() to non-zero at that destination.

I think the global time-reap() option doesn't apply, because we fall into the second class of writing to a file without a template, and the file is held open indefinitely. We never drop to the third class of applying the global option.

Also, it is time-reap, not time_reap.

I think time-reap(60) may be too long for skynet, which writes often, and so is likely to want to log to the file within a minute before doing its hourly purge.

 

[cmkelley]

I quite agree with you about the poor documentation of this "new functionality". I also thought the reason for the change was poorly understood. If one is to have a file destination at all, then the change completely breaks the prior behavior if there is any other process that addresses the file. It appears our scenario is an edge case. From https://github.com/syslog-ng/syslog-ng/pull/2798:

The PR also introduces a new functionality: If the pipe() or file() destination's filepath does not have a template, the time-reap() is not inherited from the global options, but is disabled, by default. The user can override this by explicitly setting time-reap() to non-zero at that destination.

I think the global time-reap() option doesn't apply, because we fall into the second class of writing to a file without a template, and the file is held open indefinitely. We never drop to the third class of applying the global option.

Also, it is time-reap, not time_reap.

I think time-reap(60) may be too long for skynet, which writes often, and so is likely to want to log to the file within a minute before doing its hourly purge.

Oh FFS, yes, you're correct that it never drops to the 3rd class - that explains why it didn't work when I made it global. I'm sure glad you have time to hunt this crap down, because I don't. This isn't the first time either, there was something between 3.17 and 3.19 that made me require 3.19 or higher going forward.

I _think_ syslog-ng doesn't care if it's _ or - ... Foolish consistency being the hobgoblin of little minds and all, I'm going to try to see if time_reap works since all the other variables are documented at '-', but even in their sample files show up as '_'. 'time_reap' didn't cause an error in the global defaults. EDIT: Confirmed, 'time_reap' works fine.

If I read it correctly, (60) was the previous default, so in theory 60 shouldn't be too long for Skynet (i.e. it worked before). I can't find/think of any way to come up with an 'optimum'. Did you just pick 2 seconds or did you look at the skynet-0 log to see what was necessary?

 

[elorimer]

I took the 2 second parameter from the example in that github pull without any thought, and I agree that it would have been 60 before and must have worked, but wouldn't work when changed to forever. I suspect that for the volume of messages we are dealing with here there is not much of a performance advantage in leaving the file open in the first place.

 

[cmkelley]

I took the 2 second parameter from the example in that github pull without any thought, and I agree that it would have been 60 before and must have worked, but wouldn't work when changed to forever. I suspect that for the volume of messages we are dealing with here there is not much of a performance advantage in leaving the file open in the first place.

Agree, I'm just a proponent of changing as little as possible. There's got to be some balance between ensuring the file gets closed periodically and not excessively closing and re-opening the file. On very slow thumb drives it might make a measurable difference, maybe.

I'm worried this problem will show up somewhere else, I'm thinking about creating a global template to ensure it doesn't. I'm a bit brain-dead right now to have a good think on that though.

 

[elorimer]

I'm thinking about creating a global template to ensure it doesn't

If my specific message template didn't work, I'm not sure a similar global message template will work, although I came across that as an example; there is already a default message template. In a few places the templating here for pipe() and file() is described as a filepath template, which might include a file name template if one is, for example, writing separate files for separate sources or hosts.

So perhaps it is best just to do the time reap fix and watch out for these guys to do another crazy ivan in the future.

 

[cmkelley]

If my specific message template didn't work, I'm not sure a similar global message template will work, although I came across that as an example; there is already a default message template. In a few places the templating here for pipe() and file() is described as a filepath template, which might include a file name template if one is, for example, writing separate files for separate sources or hosts.

So perhaps it is best just to do the time reap fix and watch out for these guys to do another crazy ivan in the future.

I have no doubt there will be another Crazy Ivan. Maybe they'll go port instead of starboard in the bottom of the hour.

For now, I'll leave the time_reap(60) in the skynet filter rather than try to play with a global template. I don't have time to fool with that.

Unfortunately, I was in the middle of (slowly) adding configuration backup and restore functionality when this came up, and that's not complete, and I'm not near cleaver enough to figure out how to fix just the skynet issue in the master repository. :-(

 

[elorimer]

I'll leave the time_reap(60) in the skynet filter

Destination definition, not filter. I'm very literal, Jonesie.

 

[andresmorago]

hello
i havent been able to get this to work. skynet-0.log is empty.

i have tried to modify the destination definition with the time-reap(60) but so far nothing comes up
/opt/etc/syslog-ng.d/skynet

# this MUST BE the file configured in Skynet as the syslog.log location
# DO NOT use /tmp/syslog.log or /opt/var/log/messages here!

destination d_skynet {
#    file("/opt/var/log/skynet-0.log");
    file("/opt/var/log/skynet-0.log", time-reap(60));
};

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

# final flag stops processing of messages matching the f_skynet filter
log {
    source(src);
    filter(f_skynet);
    destination(d_skynet);
    flags(final);
};

#eof

by deleting the time-reap and leaving the skynet file as is, it will start showing data on skynet log again but it will erase after some time

 

[Butterfly Bones]

i have tried to modify the destination definition with the time-reap(60) but so far nothing comes up
/opt/etc/syslog-ng.d/skynet

Change time-reap(60) to time-reap(2) and it should work.

destination d_skynet {
   file("/opt/var/log/skynet-0.log", time-reap(2));
};

 

[andresmorago]

hi
it doesnt work either. just changed it and executed scribe restart
skynet-0.log goes back to a blank file
if i use the regular expression

destination d_skynet {
   file("/opt/var/log/skynet-0.log");
};

skynet-0.log will populate for some time but returns to blank after

 

[cmkelley]

hello
i havent been able to get this to work. skynet-0.log is empty.

i have tried to modify the destination definition with the time-reap(60) but so far nothing comes up
/opt/etc/syslog-ng.d/skynet

# this MUST BE the file configured in Skynet as the syslog.log location
# DO NOT use /tmp/syslog.log or /opt/var/log/messages here!

destination d_skynet {
#    file("/opt/var/log/skynet-0.log");
    file("/opt/var/log/skynet-0.log", time-reap(60));
};

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

# final flag stops processing of messages matching the f_skynet filter
log {
    source(src);
    filter(f_skynet);
    destination(d_skynet);
    flags(final);
};

#eof

by deleting the time-reap and leaving the skynet file as is, it will start showing data on skynet log again but it will erase after some time

I'm not sure syslog-ng allows comments inside of definitions. Try taking out the "# file("/opt/var/log/skynet-0.log");" line. Long shot, but I'm not sure what else to try. Also, Skynet will clear skynet-0 every hour, but it should repopulate after that.

 

[shark]

hi
it doesnt work either. just changed it and executed scribe restart
skynet-0.log goes back to a blank file
if i use the regular expression

destination d_skynet {
   file("/opt/var/log/skynet-0.log");
};

skynet-0.log will populate for some time but returns to blank after

# this MUST BE the file configured in Skynet as the syslog.log location
# DO NOT use /tmp/syslog.log or /opt/var/log/messages here!
destination d_skynet {
    file("/opt/var/log/skynet-0.log", time-reap(2));
};

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

# final flag stops processing of messages matching the f_skynet filter
log {
    source(src);
    filter(f_skynet);
    destination(d_skynet);
    flags(final);
};

#eof

Just copy this and replace your whole file with it, dont do anything different like adding commented stuff where you should not...

 

[andresmorago]

thanks
will try

 

[elorimer]

destination d_skynet {
# file("/opt/var/log/skynet-0.log");
file("/opt/var/log/skynet-0.log", time-reap(60));
};

I think it may be that commenting out lines might work--there are examples of this in the syslog-ng conf files--but one must be careful of this for another reason: @Jack Yaz 's uiScribe script.

If I follow, uiScribe builds its log by first running syslog-ng in a pretend way and piping the output to a file (this is the preprocess-into command). This captures the full configuration of how it will operate when syslog-ng is run, including all the included syslog-ng.d files.

Then, it takes that output, and selects all the lines that have "destination" in them, and the line after. This eliminates source definitions and some other things. Then, from that, it selects all the lines that have "file" in them, and then strips out any line with "#" in it. From that, it strips out the "file(" parts, so you have just a list of the file names of destinations. Pretty slick.

This makes a few assumptions. The first is that the configuration files are written in this stylized way, with the file line on the line after the destination line. Syslog-ng will accept one long line, and will accept in line definitions too: you could I think only have log statements with in-line definitions, like so:

destination d_skynet { file("/opt/var/log/skynet-0.log", time-reap(60)); };

Another is that the file definition you want is on that next line.

In the above example, though, I think the line that gets captured is the commented-out line, and the un-commented line, because it is not the next line after "destination", is not selected. Then the commented-out line is stripped out, and this destination doesn't make it to the list of logs going to the UI.

 

[andresmorago]

# this MUST BE the file configured in Skynet as the syslog.log location
# DO NOT use /tmp/syslog.log or /opt/var/log/messages here!
destination d_skynet {
    file("/opt/var/log/skynet-0.log", time-reap(2));
};

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

# final flag stops processing of messages matching the f_skynet filter
log {
    source(src);
    filter(f_skynet);
    destination(d_skynet);
    flags(final);
};

#eof

Just copy this and replace your whole file with it, dont do anything different like adding commented stuff where you should not...

Thanks. It’s been working since 8 hours.