static gboolean
_parse_timestamp(SnmpTrapdHeaderParser *self)
{
GTimeVal now;
cached_g_current_time(&now);
time_t now_tv_sec = (time_t) now.tv_sec;
LogStamp *stamp = &self->nv_context->msg->timestamps[LM_TS_STAMP];
stamp->tv_usec = 0;
stamp->zone_offset = -1;
/* NOTE: we initialize various unportable fields in tm using a
* localtime call, as the value of tm_gmtoff does matter but it does
* not exist on all platforms and 0 initializing it causes trouble on
* time-zone barriers */
struct tm tm;
cached_localtime(&now_tv_sec, &tm);
if (!scan_std_timestamp(self->input, (gint *)self->input_len, &tm))
return FALSE;
tm.tm_isdst = -1;
stamp->tv_sec = cached_mktime(&tm);
stamp->zone_offset = get_local_timezone_ofs(stamp->tv_sec);
return TRUE;
}
/* NOTE: lock should be acquired for writing before calling this function. */
static void
_advance_time_based_on_message(PatternDB *self, PDBProcessParams *process_params, const LogStamp *ls)
{
GTimeVal now;
/* clamp the current time between the timestamp of the current message
* (low limit) and the current system time (high limit). This ensures
* that incorrect clocks do not skew the current time know by the
* correllation engine too much. */
cached_g_current_time(&now);
self->last_tick = now;
if (ls->tv_sec < now.tv_sec)
now.tv_sec = ls->tv_sec;
/* the expire callback uses this pointer to find the process_params it
* needs to emit messages. ProcessParams itself is a per-thread value,
* however the timer callback is executing with the writer lock held.
* There's no other mechanism to pass this pointer to the timer callback,
* so we add it to PatternDB, but make sure it is properly protected by
* locks.
* */
self->timer_process_params = process_params;
timer_wheel_set_time(self->timer_wheel, now.tv_sec);
self->timer_process_params = NULL;
msg_debug("Advancing patterndb current time because of an incoming message",
evt_tag_long("utc", timer_wheel_get_time(self->timer_wheel)));
}
time_t
cached_g_current_time_sec()
{
GTimeVal now;
cached_g_current_time(&now);
return now.tv_sec;
}
PatternDB *
pattern_db_new(void)
{
PatternDB *self = g_new0(PatternDB, 1);
self->ruleset = pdb_rule_set_new();
_init_state(self);
cached_g_current_time(&self->last_tick);
g_static_rw_lock_init(&self->lock);
return self;
}
/*
* This function can be called any time when pattern-db is not processing
* messages, but we expect the correllation timer to move forward. It
* doesn't need to be called absolutely regularly as it'll use the current
* system time to determine how much time has passed since the last
* invocation. See the timing comment at pattern_db_process() for more
* information.
*/
void
pattern_db_timer_tick(PatternDB *self)
{
GTimeVal now;
glong diff;
PDBProcessParams process_params_p = {0};
PDBProcessParams *process_params = &process_params_p;
g_static_rw_lock_writer_lock(&self->lock);
self->timer_process_params = process_params;
cached_g_current_time(&now);
diff = g_time_val_diff(&now, &self->last_tick);
if (diff > 1e6)
{
glong diff_sec = (glong) (diff / 1e6);
timer_wheel_set_time(self->timer_wheel, timer_wheel_get_time(self->timer_wheel) + diff_sec);
msg_debug("Advancing patterndb current time because of timer tick",
evt_tag_long("utc", timer_wheel_get_time(self->timer_wheel)));
/* update last_tick, take the fraction of the seconds not calculated into this update into account */
self->last_tick = now;
g_time_val_add(&self->last_tick, - (glong)(diff - diff_sec * 1e6));
}
else if (diff < 0)
{
/* time moving backwards, this can only happen if the computer's time
* is changed. We don't update patterndb's idea of the time now, wait
* another tick instead to update that instead.
*/
self->last_tick = now;
}
self->timer_process_params = NULL;
g_static_rw_lock_writer_unlock(&self->lock);
_flush_emitted_messages(self, process_params);
}
/* FIXME: this function should really be exploded to a lot of smaller functions... (Bazsi) */
static gboolean
log_msg_parse_date(LogMessage *self, const guchar **data, gint *length, guint parse_flags, glong assume_timezone)
{
const guchar *src = *data;
gint left = *length;
GTimeVal now;
struct tm tm;
gint unnormalized_hour;
cached_g_current_time(&now);
if ((parse_flags & LP_SYSLOG_PROTOCOL) == 0)
{
/* Cisco timestamp extensions, the first '*' indicates that the clock is
* unsynced, '.' if it is known to be synced */
if (G_UNLIKELY(src[0] == '*'))
{
log_msg_set_value(self, is_synced, "0", 1);
src++;
left--;
}
else if (G_UNLIKELY(src[0] == '.'))
{
log_msg_set_value(self, is_synced, "1", 1);
src++;
left--;
}
}
/* If the next chars look like a date, then read them as a date. */
if (__is_iso_stamp((const gchar *)src, left))
{
if (!__parse_iso_stamp(&now, self, &tm, &src, &left))
goto error;
tm.tm_isdst = -1;
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
}
else if ((parse_flags & LP_SYSLOG_PROTOCOL) == 0)
{
glong usec = 0;
if (!__parse_bsd_timestamp(&src, &left, &now, &tm, &usec))
goto error;
self->timestamps[LM_TS_STAMP].tv_usec = usec;
}
else
{
if (left >= 1 && src[0] == '-')
{
/* NILVALUE */
self->timestamps[LM_TS_STAMP] = self->timestamps[LM_TS_RECVD];
*length = --left;
*data = ++src;
return TRUE;
}
else
return FALSE;
}
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
__set_zone_offset(&(self->timestamps[LM_TS_STAMP]), assume_timezone);
self->timestamps[LM_TS_STAMP].tv_sec = __get_normalized_time(self->timestamps[LM_TS_STAMP], tm.tm_hour, unnormalized_hour);
*data = src;
*length = left;
return TRUE;
error:
/* no recognizable timestamp, use current time */
self->timestamps[LM_TS_STAMP] = self->timestamps[LM_TS_RECVD];
return FALSE;
}
/* FIXME: this function should really be exploded to a lot of smaller functions... (Bazsi) */
static gboolean
log_msg_parse_date(LogMessage *self, const guchar **data, gint *length, guint parse_flags, glong assume_timezone)
{
const guchar *src = *data;
gint left = *length;
GTimeVal now;
struct tm tm;
gint unnormalized_hour;
cached_g_current_time(&now);
if ((parse_flags & LP_SYSLOG_PROTOCOL) == 0)
{
/* Cisco timestamp extensions, the first '*' indicates that the clock is
* unsynced, '.' if it is known to be synced */
if (G_UNLIKELY(src[0] == '*'))
{
log_msg_set_value(self, is_synced, "0", 1);
src++;
left--;
}
else if (G_UNLIKELY(src[0] == '.'))
{
log_msg_set_value(self, is_synced, "1", 1);
src++;
left--;
}
}
/* If the next chars look like a date, then read them as a date. */
if (left >= 19 && src[4] == '-' && src[7] == '-' && src[10] == 'T' && src[13] == ':' && src[16] == ':')
{
/* RFC3339 timestamp, expected format: YYYY-MM-DDTHH:MM:SS[.frac]<+/->ZZ:ZZ */
gint hours, mins;
time_t now_tv_sec = (time_t)now.tv_sec;
self->timestamps[LM_TS_STAMP].tv_usec = 0;
/* NOTE: we initialize various unportable fields in tm using a
* localtime call, as the value of tm_gmtoff does matter but it does
* not exist on all platforms and 0 initializing it causes trouble on
* time-zone barriers */
cached_localtime(&now_tv_sec, &tm);
if (!scan_iso_timestamp((const gchar **) &src, &left, &tm))
{
goto error;
}
self->timestamps[LM_TS_STAMP].tv_usec = 0;
if (left > 0 && *src == '.')
{
gulong frac = 0;
gint div = 1;
/* process second fractions */
src++;
left--;
while (left > 0 && div < 10e5 && isdigit(*src))
{
frac = 10 * frac + (*src) - '0';
div = div * 10;
src++;
left--;
}
while (isdigit(*src))
{
src++;
left--;
}
self->timestamps[LM_TS_STAMP].tv_usec = frac * (1000000 / div);
}
if (left > 0 && *src == 'Z')
{
/* Z is special, it means UTC */
self->timestamps[LM_TS_STAMP].zone_offset = 0;
src++;
left--;
}
else if (left >= 5 && (*src == '+' || *src == '-') &&
isdigit(*(src+1)) && isdigit(*(src+2)) && *(src+3) == ':' && isdigit(*(src+4)) && isdigit(*(src+5)) && !isdigit(*(src+6)))
{
/* timezone offset */
gint sign = *src == '-' ? -1 : 1;
hours = (*(src+1) - '0') * 10 + *(src+2) - '0';
mins = (*(src+4) - '0') * 10 + *(src+5) - '0';
self->timestamps[LM_TS_STAMP].zone_offset = sign * (hours * 3600 + mins * 60);
src += 6;
left -= 6;
}
/* we convert it to UTC */
tm.tm_isdst = -1;
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
}
else if ((parse_flags & LP_SYSLOG_PROTOCOL) == 0)
{
if (left >= 21 && src[3] == ' ' && src[6] == ' ' && src[11] == ' ' && src[14] == ':' && src[17] == ':' && (src[20] == ':' || src[20] == ' ') &&
(isdigit(src[7]) && isdigit(src[8]) && isdigit(src[9]) && isdigit(src[10])))
{
/* PIX timestamp, expected format: MMM DD YYYY HH:MM:SS: */
/* ASA timestamp, expected format: MMM DD YYYY HH:MM:SS */
time_t now_tv_sec = (time_t)now.tv_sec;
cached_localtime(&now_tv_sec, &tm);
if (!scan_pix_timestamp((const gchar **) &src, &left, &tm))
goto error;
if (*src == ':')
{
src++;
left--;
}
tm.tm_isdst = -1;
/* NOTE: no timezone information in the message, assume it is local time */
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
self->timestamps[LM_TS_STAMP].tv_usec = 0;
}
else if (left >= 21 && src[3] == ' ' && src[6] == ' ' && src[9] == ':' && src[12] == ':' && src[15] == ' ' &&
isdigit(src[16]) && isdigit(src[17]) && isdigit(src[18]) && isdigit(src[19]) && isspace(src[20]))
{
/* LinkSys timestamp, expected format: MMM DD HH:MM:SS YYYY */
time_t now_tv_sec = (time_t)now.tv_sec;
cached_localtime(&now_tv_sec, &tm);
if (!scan_linksys_timestamp((const gchar **) &src, &left, &tm))
goto error;
tm.tm_isdst = -1;
/* NOTE: no timezone information in the message, assume it is local time */
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
self->timestamps[LM_TS_STAMP].tv_usec = 0;
}
else if (left >= 15 && src[3] == ' ' && src[6] == ' ' && src[9] == ':' && src[12] == ':')
{
/* RFC 3164 timestamp, expected format: MMM DD HH:MM:SS ... */
struct tm nowtm;
glong usec = 0;
time_t now_tv_sec = (time_t)now.tv_sec;
cached_localtime(&now_tv_sec, &nowtm);
tm = nowtm;
if (!scan_bsd_timestamp((const gchar **) &src, &left, &tm))
goto error;
if (left > 0 && src[0] == '.')
{
gulong frac = 0;
gint div = 1;
gint i = 1;
/* gee, funny Cisco extension, BSD timestamp with fraction of second support */
while (i < left && div < 10e5 && isdigit(src[i]))
{
frac = 10 * frac + (src[i]) - '0';
div = div * 10;
i++;
}
while (i < left && isdigit(src[i]))
i++;
usec = frac * (1000000 / div);
left -= i;
src += i;
}
/* detect if the message is coming from last year. If current
* month is January, and the message comes from December, the
* year of the message is inferred to be last year.
* Conversely, if current month is December, and message comes
* from January, year of message is inferred to be next year.
*/
if (tm.tm_mon == 11 && nowtm.tm_mon == 0)
tm.tm_year--;
else if (tm.tm_mon == 0 && nowtm.tm_mon == 11)
tm.tm_year++;
/* NOTE: no timezone information in the message, assume it is local time */
unnormalized_hour = tm.tm_hour;
self->timestamps[LM_TS_STAMP].tv_sec = cached_mktime(&tm);
self->timestamps[LM_TS_STAMP].tv_usec = usec;
}
else
{
goto error;
}
}
else
{
if (left >= 1 && src[0] == '-')
{
/* NILVALUE */
self->timestamps[LM_TS_STAMP] = self->timestamps[LM_TS_RECVD];
*length = --left;
*data = ++src;
return TRUE;
}
else
return FALSE;
}
/* NOTE: mktime() returns the time assuming that the timestamp we
* received was in local time. This is not true, as there's a
* zone_offset in the timestamp as well. We need to adjust this offset
* by adding the local timezone offset at the specific time to get UTC,
* which means that tv_sec becomes as if tm was in the 00:00 timezone.
* Also we have to take into account that at the zone barriers an hour
* might be skipped or played twice this is what the
* (tm.tm_hour - * unnormalized_hour) part fixes up. */
if (self->timestamps[LM_TS_STAMP].zone_offset == -1)
{
self->timestamps[LM_TS_STAMP].zone_offset = assume_timezone;
}
if (self->timestamps[LM_TS_STAMP].zone_offset == -1)
{
self->timestamps[LM_TS_STAMP].zone_offset = get_local_timezone_ofs(self->timestamps[LM_TS_STAMP].tv_sec);
}
self->timestamps[LM_TS_STAMP].tv_sec = self->timestamps[LM_TS_STAMP].tv_sec +
get_local_timezone_ofs(self->timestamps[LM_TS_STAMP].tv_sec) -
(tm.tm_hour - unnormalized_hour) * 3600 - self->timestamps[LM_TS_STAMP].zone_offset;
*data = src;
*length = left;
return TRUE;
error:
/* no recognizable timestamp, use current time */
self->timestamps[LM_TS_STAMP] = self->timestamps[LM_TS_RECVD];
return FALSE;
}
gboolean
log_macro_expand(GString *result, gint id, gboolean escape, LogTemplateOptions *opts, gint tz, gint32 seq_num, const gchar *context_id, LogMessage *msg)
{
static LogTemplateOptions default_opts = { TRUE, TS_FMT_BSD, 0, { NULL, NULL }, { NULL, NULL } };
if (!opts)
opts = &default_opts;
switch (id)
{
case M_FACILITY:
{
/* facility */
const char *n;
n = syslog_name_lookup_name_by_value(msg->pri & LOG_FACMASK, sl_facilities);
if (n)
{
g_string_append(result, n);
}
else
{
format_uint32_padded(result, 0, 0, 16, (msg->pri & LOG_FACMASK) >> 3);
}
break;
}
case M_FACILITY_NUM:
{
format_uint32_padded(result, 0, 0, 10, (msg->pri & LOG_FACMASK) >> 3);
break;
}
case M_LEVEL:
{
/* level */
const char *n;
n = syslog_name_lookup_name_by_value(msg->pri & LOG_PRIMASK, sl_levels);
if (n)
{
g_string_append(result, n);
}
else
{
format_uint32_padded(result, 0, 0, 10, msg->pri & LOG_PRIMASK);
}
break;
}
case M_LEVEL_NUM:
{
format_uint32_padded(result, 0, 0, 10, msg->pri & LOG_PRIMASK);
break;
}
case M_TAG:
{
format_uint32_padded(result, 2, '0', 16, msg->pri);
break;
}
case M_TAGS:
{
log_msg_print_tags(msg, result);
break;
}
case M_BSDTAG:
{
format_uint32_padded(result, 0, 0, 10, (msg->pri & LOG_PRIMASK));
g_string_append_c(result, (((msg->pri & LOG_FACMASK) >> 3) + 'A'));
break;
}
case M_PRI:
{
format_uint32_padded(result, 0, 0, 10, msg->pri);
break;
}
case M_HOST:
{
if (msg->flags & LF_CHAINED_HOSTNAME)
{
/* host */
const gchar *p1, *p2;
int remaining, length;
gssize host_len;
const gchar *host = log_msg_get_value(msg, LM_V_HOST, &host_len);
p1 = memchr(host, '@', host_len);
if (p1)
p1++;
else
p1 = host;
remaining = host_len - (p1 - host);
p2 = memchr(p1, '/', remaining);
length = p2 ? p2 - p1
: host_len - (p1 - host);
result_append(result, p1, length, escape);
}
else
{
result_append_value(result, msg, LM_V_HOST, escape);
}
break;
}
case M_SDATA:
if (escape)
{
GString *sdstr = g_string_sized_new(0);
log_msg_append_format_sdata(msg, sdstr, seq_num);
result_append(result, sdstr->str, sdstr->len, TRUE);
g_string_free(sdstr, TRUE);
}
else
{
log_msg_append_format_sdata(msg, result, seq_num);
}
break;
case M_MSGHDR:
if ((msg->flags & LF_LEGACY_MSGHDR))
{
/* fast path for now, as most messages come from legacy devices */
result_append_value(result, msg, LM_V_LEGACY_MSGHDR, escape);
}
else
{
/* message, complete with program name and pid */
gssize len;
len = result->len;
result_append_value(result, msg, LM_V_PROGRAM, escape);
if (len != result->len)
{
const gchar *pid = log_msg_get_value(msg, LM_V_PID, &len);
if (len > 0)
{
result_append(result, "[", 1, FALSE);
result_append(result, pid, len, escape);
result_append(result, "]", 1, FALSE);
}
result_append(result, ": ", 2, FALSE);
}
}
break;
case M_MESSAGE:
if (cfg_is_config_version_older(configuration, 0x0300))
log_macro_expand(result, M_MSGHDR, escape, opts, tz, seq_num, context_id, msg);
result_append_value(result, msg, LM_V_MESSAGE, escape);
break;
case M_SOURCE_IP:
{
gchar *ip;
if (msg->saddr && (g_sockaddr_inet_check(msg->saddr) ||
#if ENABLE_IPV6
g_sockaddr_inet6_check(msg->saddr))
#else
0)
#endif
)
{
gchar buf[MAX_SOCKADDR_STRING];
g_sockaddr_format(msg->saddr, buf, sizeof(buf), GSA_ADDRESS_ONLY);
ip = buf;
}
else
{
ip = "127.0.0.1";
}
result_append(result, ip, strlen(ip), escape);
break;
}
case M_SEQNUM:
{
if (seq_num)
{
format_uint32_padded(result, 0, 0, 10, seq_num);
}
break;
}
case M_CONTEXT_ID:
{
if (context_id)
{
result_append(result, context_id, strlen(context_id), escape);
}
break;
}
case M_LOGHOST:
{
gsize hname_len;
const gchar *hname = get_local_hostname(&hname_len);
result_append(result, hname, hname_len, escape);
break;
}
case M_SYSUPTIME:
{
GTimeVal ct;
g_get_current_time(&ct);
format_uint64_padded(result, 0, 0, 10, g_time_val_diff(&ct, &app_uptime) / 1000 / 10);
break;
}
default:
{
/* year, month, day */
struct tm *tm, tm_storage;
gchar buf[64];
gint length;
time_t t;
LogStamp *stamp, sstamp;
glong zone_ofs;
guint tmp_hour;
if (id >= M_TIME_FIRST && id <= M_TIME_LAST)
{
stamp = &msg->timestamps[LM_TS_STAMP];
}
else if (id >= M_TIME_FIRST + M_RECVD_OFS && id <= M_TIME_LAST + M_RECVD_OFS)
{
id -= M_RECVD_OFS;
stamp = &msg->timestamps[LM_TS_RECVD];
}
else if (id >= M_TIME_FIRST + M_STAMP_OFS && id <= M_TIME_LAST + M_STAMP_OFS)
{
id -= M_STAMP_OFS;
stamp = &msg->timestamps[LM_TS_STAMP];
}
else if (id >= M_TIME_FIRST + M_CSTAMP_OFS && id <= M_TIME_LAST + M_CSTAMP_OFS)
{
GTimeVal tv;
id -= M_CSTAMP_OFS;
cached_g_current_time(&tv);
sstamp.tv_sec = tv.tv_sec;
sstamp.tv_usec = tv.tv_usec;
sstamp.zone_offset = -1;
stamp = &sstamp;
}
else
{
g_assert_not_reached();
break;
}
/* try to use the following zone values in order:
* destination specific timezone, if one is specified
* message specific timezone, if one is specified
* local timezone
*/
zone_ofs = (opts->time_zone_info[tz] != NULL ? time_zone_info_get_offset(opts->time_zone_info[tz], stamp->tv_sec) : stamp->zone_offset);
if (zone_ofs == -1)
zone_ofs = stamp->zone_offset;
t = stamp->tv_sec + zone_ofs;
cached_gmtime(&t, &tm_storage);
tm = &tm_storage;
switch (id)
{
case M_WEEK_DAY_ABBREV:
g_string_append_len(result, weekday_names_abbrev[tm->tm_wday], 3);
break;
case M_WEEK_DAY_NAME:
g_string_append(result, weekday_names[tm->tm_wday]);
break;
case M_WEEK_DAY:
format_uint32_padded(result, 0, 0, 10, tm->tm_wday + 1);
break;
case M_WEEK:
format_uint32_padded(result, 2, '0', 10, (tm->tm_yday - (tm->tm_wday - 1 + 7) % 7 + 7) / 7);
break;
case M_YEAR:
format_uint32_padded(result, 4, '0', 10, tm->tm_year + 1900);
break;
case M_YEAR_DAY:
format_uint32_padded(result, 3, '0', 10, tm->tm_yday + 1);
break;
case M_MONTH:
format_uint32_padded(result, 2, '0', 10, tm->tm_mon + 1);
break;
case M_MONTH_WEEK:
format_uint32_padded(result, 0, 0, 10, ((tm->tm_mday / 7) + ((tm->tm_wday > 0) && ((tm->tm_mday % 7) >= tm->tm_wday))));
break;
case M_MONTH_ABBREV:
g_string_append_len(result, month_names_abbrev[tm->tm_mon], 3);
break;
case M_MONTH_NAME:
g_string_append(result, month_names[tm->tm_mon]);
break;
case M_DAY:
format_uint32_padded(result, 2, '0', 10, tm->tm_mday);
break;
case M_HOUR:
format_uint32_padded(result, 2, '0', 10, tm->tm_hour);
break;
case M_HOUR12:
if (tm->tm_hour < 12)
tmp_hour = tm->tm_hour;
else
tmp_hour = tm->tm_hour - 12;
if (tmp_hour == 0)
tmp_hour = 12;
format_uint32_padded(result, 2, '0', 10, tmp_hour);
break;
case M_MIN:
format_uint32_padded(result, 2, '0', 10, tm->tm_min);
break;
case M_SEC:
format_uint32_padded(result, 2, '0', 10, tm->tm_sec);
break;
case M_MSEC:
format_uint32_padded(result, 3, '0', 10, stamp->tv_usec/1000);
break;
case M_USEC:
format_uint32_padded(result, 6, '0', 10, stamp->tv_usec);
break;
case M_AMPM:
g_string_append(result, tm->tm_hour < 12 ? "AM" : "PM");
break;
case M_DATE:
case M_STAMP:
case M_ISODATE:
case M_FULLDATE:
case M_UNIXTIME:
{
gint format = id == M_DATE ? TS_FMT_BSD :
id == M_ISODATE ? TS_FMT_ISO :
id == M_FULLDATE ? TS_FMT_FULL :
id == M_UNIXTIME ? TS_FMT_UNIX :
opts->ts_format;
log_stamp_append_format(stamp, result, format, zone_ofs, opts->frac_digits);
break;
}
case M_TZ:
case M_TZOFFSET:
length = format_zone_info(buf, sizeof(buf), zone_ofs);
g_string_append_len(result, buf, length);
break;
}
break;
}
}
