util/log: rotate calendar intervals on local-time boundaries

With rotate-interval set to minute, hour or day, rotations were not
aligned to the local time boundaries. The first rotation was computed
by SCGetSecondsUntil(), which overshoots the next hour by one minute
(hh:01:00) and the next day by one hour and one minute (01:01:00).
Every following rotation was re-armed with a fixed interval
(e.g. 86400 s) from the time of the rotation.

Local days are not always 86400 s long, so the day rotation also moved
by the DST shift on every DST transition and stayed there until the
next one. A file named after a date then held events of the next day.

Instead, this commit rotates logs when the local minute, hour or date
changes. The daily rotation now happens at local midnight.
On SIGHUP, the period is recorded before the file is reopened, so a boundary
(the next minute/hour/day) passing during the reopen leads to an extra
reopen instead of a missed rotation.

Ticket: #9139
pull/16497/head
Lukas Sismis 1 month ago committed by Victor Julien
parent 3fe8ac21d0
commit da64eace18

@ -485,6 +485,12 @@ Eve-log can be configured to rotate based on time.
The example above creates a new log file each minute, where the filename contains The example above creates a new log file each minute, where the filename contains
a timestamp. Other supported ``rotate-interval`` values are ``hour`` and ``day``. a timestamp. Other supported ``rotate-interval`` values are ``hour`` and ``day``.
These values rotate the log file when the minute, hour or date of the local time
changes. For example, ``day`` rotates at local midnight, also across daylight
saving time changes, or at the first local time of the new date where such a
change skips midnight. When the clock is set back at the end of daylight saving
time, the repeated hour is part of the same hour period, so with ``hour`` a
single file holds both passes of that hour.
In addition to this, it is also possible to specify the ``rotate-interval`` as a In addition to this, it is also possible to specify the ``rotate-interval`` as a
relative value. One example is to rotate the log file each X seconds. relative value. One example is to rotate the log file each X seconds.
@ -498,7 +504,10 @@ relative value. One example is to rotate the log file each X seconds.
The example above rotates eve-log each 30 seconds. This could be replaced with The example above rotates eve-log each 30 seconds. This could be replaced with
``30m`` to rotate every 30 minutes, ``30h`` to rotate every 30 hours, ``30d`` ``30m`` to rotate every 30 minutes, ``30h`` to rotate every 30 hours, ``30d``
to rotate every 30 days, or ``30w`` to rotate every 30 weeks. to rotate every 30 days, or ``30w`` to rotate every 30 weeks. Relative values
are counted from startup or the last SIGHUP and are not aligned to the local
time, so e.g. ``24h`` or ``1d`` do not rotate at local midnight like ``day``
does.
.. _multiple-eve-instances: .. _multiple-eve-instances:

@ -69,6 +69,7 @@
#include "util-cidr.h" #include "util-cidr.h"
#include "util-coredump-config.h" #include "util-coredump-config.h"
#include "util-unittest-helper.h" #include "util-unittest-helper.h"
#include "util-logopenfile.h"
#include "util-rule-vars.h" #include "util-rule-vars.h"
#include "util-classification-config.h" #include "util-classification-config.h"
#include "util-threshold-config.h" #include "util-threshold-config.h"
@ -134,6 +135,7 @@ static void RegisterUnittests(void)
{ {
UTHRegisterTests(); UTHRegisterTests();
SCTimeRegisterTests(); SCTimeRegisterTests();
LogFileRegisterTests();
StreamTcpRegisterTests(); StreamTcpRegisterTests();
SigRegisterTests(); SigRegisterTests();
SCReputationRegisterTests(); SCReputationRegisterTests();

@ -32,6 +32,8 @@
#include "util-conf.h" #include "util-conf.h"
#include "util-path.h" #include "util-path.h"
#include "util-misc.h" #include "util-misc.h"
#include "util-time.h"
#include "util-unittest.h"
#include "log-maintenance.h" #include "log-maintenance.h"
#if defined(HAVE_SYS_UN_H) && defined(HAVE_SYS_SOCKET_H) && defined(HAVE_SYS_TYPES_H) #if defined(HAVE_SYS_UN_H) && defined(HAVE_SYS_SOCKET_H) && defined(HAVE_SYS_TYPES_H)
@ -209,6 +211,75 @@ static void SCLogFileFlush(LogFileCtx *log_ctx)
SCMutexUnlock(&log_ctx->fp_mutex); SCMutexUnlock(&log_ctx->fp_mutex);
} }
/**
* \brief Get a number identifying the local day, hour or minute of tm
*
* The number is only compared for equality to detect that the local period
* changed, it is not a count of elapsed time. Counting 366 days per year keeps
* the number unique for every tm_yday (0-365), as with 365, Dec 31 of a leap
* year would get the same number as Jan 1 of the next year.
*/
static int64_t LogFileRotatePeriod(LogFileRotateUnit unit, const struct tm *tm)
{
const int64_t day = (int64_t)tm->tm_year * 366 + tm->tm_yday;
const int64_t hour = day * 24 + tm->tm_hour;
const int64_t minute = hour * 60 + tm->tm_min;
if (unit == LOGFILE_ROTATE_ON_NEW_DAY) {
return day;
}
if (unit == LOGFILE_ROTATE_ON_NEW_HOUR) {
return hour;
}
return minute;
}
/**
* \brief Record the rotation period of now and schedule the next rotation check
*
* Calendar units (minute, hour, day) are checked at the start of every local
* minute, relative intervals when the interval has passed.
*/
static void LogFileRotateArm(LogFileCtx *log_ctx, time_t now)
{
if (log_ctx->rotate_unit == LOGFILE_ROTATE_ON_FIXED_PERIOD) {
log_ctx->rotate_time = now + log_ctx->rotate_interval;
return;
}
struct tm local_tm;
struct tm *tms = SCLocalTime(now, &local_tm);
if (tms == NULL) {
return;
}
log_ctx->rotate_time = now + 60 - tms->tm_sec;
log_ctx->rotate_period = LogFileRotatePeriod(log_ctx->rotate_unit, tms);
}
/**
* \brief Update the rotation state to now and report if the log file must be rotated
*
* Calendar units rotate when the local time period changes, so rotation stays
* aligned with local midnight across DST transitions.
*
* \retval true if the log file must be rotated
*/
static bool LogFileRotateUpdate(LogFileCtx *log_ctx, time_t now)
{
if (now < log_ctx->rotate_time) {
return false;
}
if (log_ctx->rotate_unit == LOGFILE_ROTATE_ON_FIXED_PERIOD) {
log_ctx->rotate_time = now + log_ctx->rotate_interval;
return true;
}
const int64_t prev_period = log_ctx->rotate_period;
LogFileRotateArm(log_ctx, now);
return log_ctx->rotate_period != prev_period;
}
/** /**
* \brief Handle log file rotation checks and updates * \brief Handle log file rotation checks and updates
* \param log_ctx Log file context * \param log_ctx Log file context
@ -218,16 +289,14 @@ static bool HandleLogRotation(LogFileCtx *log_ctx)
{ {
if (log_ctx->rotation_flag) { if (log_ctx->rotation_flag) {
log_ctx->rotation_flag = 0; log_ctx->rotation_flag = 0;
SCConfLogReopen(log_ctx); if (log_ctx->rotate_unit != LOGFILE_ROTATE_NONE) {
if (log_ctx->flags & LOGFILE_ROTATE_INTERVAL) { LogFileRotateArm(log_ctx, time(NULL));
log_ctx->rotate_time = time(NULL) + log_ctx->rotate_interval;
} }
SCConfLogReopen(log_ctx);
return true; return true;
} else if (log_ctx->flags & LOGFILE_ROTATE_INTERVAL) { } else if (log_ctx->rotate_unit != LOGFILE_ROTATE_NONE) {
time_t now = time(NULL); if (LogFileRotateUpdate(log_ctx, time(NULL))) {
if (now >= log_ctx->rotate_time) {
SCConfLogReopen(log_ctx); SCConfLogReopen(log_ctx);
log_ctx->rotate_time = now + log_ctx->rotate_interval;
return true; return true;
} }
} }
@ -537,29 +606,24 @@ int SCConfLogOpenGeneric(
/* Rotate log file based on time */ /* Rotate log file based on time */
const char *rotate_int = SCConfNodeLookupChildValue(conf, "rotate-interval"); const char *rotate_int = SCConfNodeLookupChildValue(conf, "rotate-interval");
if (rotate_int != NULL) { if (rotate_int != NULL) {
time_t now = time(NULL);
log_ctx->flags |= LOGFILE_ROTATE_INTERVAL;
/* Use a specific time */ /* Use a specific time */
if (strcmp(rotate_int, "minute") == 0) { if (strcmp(rotate_int, "minute") == 0) {
log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_MINUTE;
log_ctx->rotate_interval = 60;
} else if (strcmp(rotate_int, "hour") == 0) { } else if (strcmp(rotate_int, "hour") == 0) {
log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_HOUR;
log_ctx->rotate_interval = 3600;
} else if (strcmp(rotate_int, "day") == 0) { } else if (strcmp(rotate_int, "day") == 0) {
log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_DAY;
log_ctx->rotate_interval = 86400;
} }
/* Use a timer */ /* Use a timer */
else { else {
log_ctx->rotate_unit = LOGFILE_ROTATE_ON_FIXED_PERIOD;
log_ctx->rotate_interval = SCParseTimeSizeString(rotate_int); log_ctx->rotate_interval = SCParseTimeSizeString(rotate_int);
if (log_ctx->rotate_interval == 0) { if (log_ctx->rotate_interval == 0) {
FatalError("invalid rotate-interval value"); FatalError("invalid rotate-interval value");
} }
log_ctx->rotate_time = now + log_ctx->rotate_interval;
} }
LogFileRotateArm(log_ctx, time(NULL));
} }
filetype = SCConfNodeLookupChildValue(conf, "filetype"); filetype = SCConfNodeLookupChildValue(conf, "filetype");
@ -1138,3 +1202,135 @@ int LogFileWrite(LogFileCtx *file_ctx, MemBuffer *buffer)
return 0; return 0;
} }
/* the test needs POSIX TZ rules, which Windows does not support */
#if defined(UNITTESTS) && !defined(OS_WIN32)
/**
* \brief Call the rotation check for the 10 seconds around every quarter hour
* from 1 hour before to 26 hours after the DST switch, as if a log
* record was written each of these seconds, and check that it rotates
* exactly when the filename pattern expands to a new name.
*
* All timezones in use have UTC offsets in multiples of 15 minutes, so the
* switch and every local hour and day start fall on a UTC quarter hour. The
* 26 hours reach the first local midnight after the switch, where a day
* rotation with a fixed length of 86400 seconds would be off by the DST shift.
*/
static int LogFileRotateTestAroundSwitch(
LogFileRotateUnit unit, const char *pattern, time_t dst_switch)
{
const time_t start = dst_switch - 3600;
const time_t end = dst_switch + 26 * 3600;
LogFileCtx ctx;
memset(&ctx, 0, sizeof(ctx));
ctx.rotate_unit = unit;
LogFileRotateArm(&ctx, start);
char file_name[32];
FAIL_IF(SCTimeToStringPattern(start, pattern, file_name, sizeof(file_name)) != 0);
int rotations = 0;
for (time_t quarter = start + 900; quarter < end; quarter += 900) {
for (time_t now = quarter - 5; now < quarter + 5; now++) {
char expected_name[32];
FAIL_IF(SCTimeToStringPattern(now, pattern, expected_name, sizeof(expected_name)) != 0);
const bool name_changed = strcmp(expected_name, file_name) != 0;
const bool rotated = LogFileRotateUpdate(&ctx, now);
FAIL_IF(rotated != name_changed);
if (rotated) {
strlcpy(file_name, expected_name, sizeof(file_name));
rotations++;
}
}
}
/* a window without any name change would prove nothing */
FAIL_IF(rotations == 0);
PASS;
}
/** \brief Set the timezone of the process, NULL for the system default */
static void LogFileRotateTestSetTimezone(const char *tz)
{
if (tz != NULL) {
setenv("TZ", tz, 1);
} else {
unsetenv("TZ");
}
tzset();
SCLocalTimeCacheReset();
}
/** \brief Check the rotation of all units around both DST switches of tz */
static int LogFileRotateTestTimezone(const char *tz, time_t dst_start, time_t dst_end)
{
const struct {
LogFileRotateUnit unit;
const char *pattern;
} units[] = {
{ LOGFILE_ROTATE_ON_NEW_MINUTE, "%Y-%m-%d-%H:%M" },
{ LOGFILE_ROTATE_ON_NEW_HOUR, "%Y-%m-%d-%H" },
{ LOGFILE_ROTATE_ON_NEW_DAY, "%Y-%m-%d" },
};
LogFileRotateTestSetTimezone(tz);
for (size_t u = 0; u < ARRAY_SIZE(units); u++) {
FAIL_IF_NOT(LogFileRotateTestAroundSwitch(units[u].unit, units[u].pattern, dst_start) == 1);
FAIL_IF_NOT(LogFileRotateTestAroundSwitch(units[u].unit, units[u].pattern, dst_end) == 1);
}
PASS;
}
/** \test minute, hour and day rotations follow the local time, also around
* DST transitions of timezones with unusual rules */
static int LogFileRotateTest01(void)
{
/* POSIX TZ rules of timezones with DST, and their DST switches in 2026 */
const struct {
const char *tz;
time_t dst_start;
time_t dst_end;
} timezones[] = {
/* America/New_York: 2026-03-08 07:00 and 2026-11-01 06:00 UTC */
{ "EST5EDT,M3.2.0,M11.1.0", 1772953200, 1793512800 },
/* America/Havana, DST start skips midnight: 2026-03-08 and 2026-11-01 05:00 UTC */
{ "CST5CDT,M3.2.0/0,M11.1.0/1", 1772946000, 1793509200 },
/* Europe/Prague: 2026-03-29 and 2026-10-25 01:00 UTC */
{ "CET-1CEST,M3.5.0,M10.5.0/3", 1774746000, 1792890000 },
/* Australia/Sydney: 2026-10-03 and 2026-04-04 16:00 UTC */
{ "AEST-10AEDT,M10.1.0,M4.1.0/3", 1791043200, 1775318400 },
/* Australia/Lord_Howe, 30 minute DST: 2026-10-03 15:30 and 2026-04-04 15:00 UTC */
{ "<+1030>-10:30<+11>-11,M10.1.0,M4.1.0", 1791041400, 1775314800 },
/* Pacific/Chatham, switches at 02:45 and 03:45: 2026-09-26 and 2026-04-04 14:00 UTC */
{ "<+1245>-12:45<+1345>,M9.5.0/2:45,M4.1.0/3:45", 1790431200, 1775311200 },
};
const char *env_tz = getenv("TZ");
char *orig_tz = env_tz != NULL ? SCStrdup(env_tz) : NULL;
FAIL_IF(env_tz != NULL && orig_tz == NULL);
int result = 1;
for (size_t i = 0; i < ARRAY_SIZE(timezones); i++) {
if (LogFileRotateTestTimezone(
timezones[i].tz, timezones[i].dst_start, timezones[i].dst_end) != 1) {
result = 0;
break;
}
}
/* restore the timezone before reporting, also when a check failed */
LogFileRotateTestSetTimezone(orig_tz);
SCFree(orig_tz);
FAIL_IF_NOT(result == 1);
PASS;
}
#endif /* UNITTESTS && !OS_WIN32 */
void LogFileRegisterTests(void)
{
#if defined(UNITTESTS) && !defined(OS_WIN32)
UtRegisterTest("LogFileRotateTest01", LogFileRotateTest01);
#endif
}

@ -73,6 +73,14 @@ typedef struct LogFileEntry_ {
TAILQ_ENTRY(LogFileEntry_) entries; TAILQ_ENTRY(LogFileEntry_) entries;
} LogFileEntry; } LogFileEntry;
typedef enum LogFileRotateUnit_ {
LOGFILE_ROTATE_NONE = 0,
LOGFILE_ROTATE_ON_FIXED_PERIOD, /* relative interval, e.g. 30s */
LOGFILE_ROTATE_ON_NEW_MINUTE,
LOGFILE_ROTATE_ON_NEW_HOUR,
LOGFILE_ROTATE_ON_NEW_DAY,
} LogFileRotateUnit;
/** Global structure for Output Context */ /** Global structure for Output Context */
typedef struct LogFileCtx_ { typedef struct LogFileCtx_ {
union { union {
@ -126,12 +134,17 @@ typedef struct LogFileCtx_ {
uint64_t reconn_timer; uint64_t reconn_timer;
/** The next time to rotate log file, if rotate interval is /** The next time to rotate log file, if rotate interval is
specified. */ specified. For calendar units, the next time to check if the
local time period changed. */
time_t rotate_time; time_t rotate_time;
/** The interval to rotate the log file */ /** The interval to rotate the log file */
uint64_t rotate_interval; uint64_t rotate_interval;
LogFileRotateUnit rotate_unit;
/** Local time period of the open file, for calendar units */
int64_t rotate_period;
/**< Used by some alert loggers like the unified ones that append /**< Used by some alert loggers like the unified ones that append
* the date onto the end of files. */ * the date onto the end of files. */
char *prefix; char *prefix;
@ -177,9 +190,6 @@ typedef struct LogFileCtx_ {
/* Min time (msecs) before trying to reconnect a Unix domain socket */ /* Min time (msecs) before trying to reconnect a Unix domain socket */
#define LOGFILE_RECONN_MIN_TIME 500 #define LOGFILE_RECONN_MIN_TIME 500
/* flags for LogFileCtx */
#define LOGFILE_ROTATE_INTERVAL 0x04
/* Default EVE output buffering size */ /* Default EVE output buffering size */
#define LOGFILE_EVE_BUFFER_SIZE 0 #define LOGFILE_EVE_BUFFER_SIZE 0
@ -199,4 +209,6 @@ void LogFileUnregister(LogFileCtx *ctx);
void LogFileFlushAll(void); void LogFileFlushAll(void);
void LogFileRotateAll(void); void LogFileRotateAll(void);
void LogFileRegisterTests(void);
#endif /* SURICATA_UTIL_LOGOPENFILE_H */ #endif /* SURICATA_UTIL_LOGOPENFILE_H */

@ -429,6 +429,18 @@ void CreateTimeString(const SCTime_t ts, char *str, size_t size)
#endif /* defined(__OpenBSD__) */ #endif /* defined(__OpenBSD__) */
#ifdef UNITTESTS
/** \brief Forget the local times cached by the calling thread, e.g. after the
* timezone was changed */
void SCLocalTimeCacheReset(void)
{
#ifdef TLS
memset(last_local_time, 0, sizeof(last_local_time));
memset(cached_minute_start, 0, sizeof(cached_minute_start));
#endif
}
#endif
/** /**
* \brief Convert broken-down time to seconds since Unix epoch. * \brief Convert broken-down time to seconds since Unix epoch.
* *

@ -139,6 +139,7 @@ SCTime_t TimeGet(void);
void TimeSet(SCTime_t); void TimeSet(SCTime_t);
void TimeSetToCurrentTime(void); void TimeSetToCurrentTime(void);
void TimeSetIncrementTime(uint32_t); void TimeSetIncrementTime(uint32_t);
void SCLocalTimeCacheReset(void);
#endif #endif
bool TimeModeIsReady(void); bool TimeModeIsReady(void);

Loading…
Cancel
Save