diff --git a/doc/userguide/output/eve/eve-json-output.rst b/doc/userguide/output/eve/eve-json-output.rst index f25a496f6e..daa4f549b5 100644 --- a/doc/userguide/output/eve/eve-json-output.rst +++ b/doc/userguide/output/eve/eve-json-output.rst @@ -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 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 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 ``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: diff --git a/src/runmode-unittests.c b/src/runmode-unittests.c index fde9c66483..78265e4b27 100644 --- a/src/runmode-unittests.c +++ b/src/runmode-unittests.c @@ -69,6 +69,7 @@ #include "util-cidr.h" #include "util-coredump-config.h" #include "util-unittest-helper.h" +#include "util-logopenfile.h" #include "util-rule-vars.h" #include "util-classification-config.h" #include "util-threshold-config.h" @@ -134,6 +135,7 @@ static void RegisterUnittests(void) { UTHRegisterTests(); SCTimeRegisterTests(); + LogFileRegisterTests(); StreamTcpRegisterTests(); SigRegisterTests(); SCReputationRegisterTests(); diff --git a/src/util-logopenfile.c b/src/util-logopenfile.c index a84e9a85e4..b9a3929244 100644 --- a/src/util-logopenfile.c +++ b/src/util-logopenfile.c @@ -32,6 +32,8 @@ #include "util-conf.h" #include "util-path.h" #include "util-misc.h" +#include "util-time.h" +#include "util-unittest.h" #include "log-maintenance.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); } +/** + * \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 * \param log_ctx Log file context @@ -218,16 +289,14 @@ static bool HandleLogRotation(LogFileCtx *log_ctx) { if (log_ctx->rotation_flag) { log_ctx->rotation_flag = 0; - SCConfLogReopen(log_ctx); - if (log_ctx->flags & LOGFILE_ROTATE_INTERVAL) { - log_ctx->rotate_time = time(NULL) + log_ctx->rotate_interval; + if (log_ctx->rotate_unit != LOGFILE_ROTATE_NONE) { + LogFileRotateArm(log_ctx, time(NULL)); } + SCConfLogReopen(log_ctx); return true; - } else if (log_ctx->flags & LOGFILE_ROTATE_INTERVAL) { - time_t now = time(NULL); - if (now >= log_ctx->rotate_time) { + } else if (log_ctx->rotate_unit != LOGFILE_ROTATE_NONE) { + if (LogFileRotateUpdate(log_ctx, time(NULL))) { SCConfLogReopen(log_ctx); - log_ctx->rotate_time = now + log_ctx->rotate_interval; return true; } } @@ -537,29 +606,24 @@ int SCConfLogOpenGeneric( /* Rotate log file based on time */ const char *rotate_int = SCConfNodeLookupChildValue(conf, "rotate-interval"); if (rotate_int != NULL) { - time_t now = time(NULL); - log_ctx->flags |= LOGFILE_ROTATE_INTERVAL; - /* Use a specific time */ if (strcmp(rotate_int, "minute") == 0) { - log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); - log_ctx->rotate_interval = 60; + log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_MINUTE; } else if (strcmp(rotate_int, "hour") == 0) { - log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); - log_ctx->rotate_interval = 3600; + log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_HOUR; } else if (strcmp(rotate_int, "day") == 0) { - log_ctx->rotate_time = now + SCGetSecondsUntil(rotate_int, now); - log_ctx->rotate_interval = 86400; + log_ctx->rotate_unit = LOGFILE_ROTATE_ON_NEW_DAY; } /* Use a timer */ else { + log_ctx->rotate_unit = LOGFILE_ROTATE_ON_FIXED_PERIOD; log_ctx->rotate_interval = SCParseTimeSizeString(rotate_int); if (log_ctx->rotate_interval == 0) { FatalError("invalid rotate-interval value"); } - log_ctx->rotate_time = now + log_ctx->rotate_interval; } + LogFileRotateArm(log_ctx, time(NULL)); } filetype = SCConfNodeLookupChildValue(conf, "filetype"); @@ -1138,3 +1202,135 @@ int LogFileWrite(LogFileCtx *file_ctx, MemBuffer *buffer) 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 +} diff --git a/src/util-logopenfile.h b/src/util-logopenfile.h index 314673ff37..869a4471c9 100644 --- a/src/util-logopenfile.h +++ b/src/util-logopenfile.h @@ -73,6 +73,14 @@ typedef struct LogFileEntry_ { TAILQ_ENTRY(LogFileEntry_) entries; } 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 */ typedef struct LogFileCtx_ { union { @@ -126,12 +134,17 @@ typedef struct LogFileCtx_ { uint64_t reconn_timer; /** 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; /** The interval to rotate the log file */ 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 * the date onto the end of files. */ char *prefix; @@ -177,9 +190,6 @@ typedef struct LogFileCtx_ { /* Min time (msecs) before trying to reconnect a Unix domain socket */ #define LOGFILE_RECONN_MIN_TIME 500 -/* flags for LogFileCtx */ -#define LOGFILE_ROTATE_INTERVAL 0x04 - /* Default EVE output buffering size */ #define LOGFILE_EVE_BUFFER_SIZE 0 @@ -199,4 +209,6 @@ void LogFileUnregister(LogFileCtx *ctx); void LogFileFlushAll(void); void LogFileRotateAll(void); +void LogFileRegisterTests(void); + #endif /* SURICATA_UTIL_LOGOPENFILE_H */ diff --git a/src/util-time.c b/src/util-time.c index 868d8ff50a..9bf8890577 100644 --- a/src/util-time.c +++ b/src/util-time.c @@ -429,6 +429,18 @@ void CreateTimeString(const SCTime_t ts, char *str, size_t size) #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. * diff --git a/src/util-time.h b/src/util-time.h index a9dec3adac..2e577ca4b5 100644 --- a/src/util-time.h +++ b/src/util-time.h @@ -139,6 +139,7 @@ SCTime_t TimeGet(void); void TimeSet(SCTime_t); void TimeSetToCurrentTime(void); void TimeSetIncrementTime(uint32_t); +void SCLocalTimeCacheReset(void); #endif bool TimeModeIsReady(void);