void
test_msg_tags()
{
gchar *name;
gint i, set;
test_msg("=== LogMessage tests ===\n");
LogMessage *msg = log_msg_new_empty();
for (set = 1; set != -1; set--)
{
for (i = NUM_TAGS; i > -1; i--)
{
name = get_tag_by_id(i);
if (set)
log_msg_set_tag_by_name(msg, name);
else
log_msg_clear_tag_by_name(msg, name);
test_msg("%s tag %d %s\n", set ? "Setting" : "Clearing", i, name);
if (set ^ log_msg_is_tag_by_id(msg, i))
test_fail("Tag is %sset now (by id) %d\n", set ? "not " : "", i);
g_free(name);
}
}
log_msg_unref(msg);
msg = log_msg_new_empty();
for (set = 1; set != -1; set--)
{
for (i = 0; i < NUM_TAGS; i++)
{
name = get_tag_by_id(i);
if (set)
log_msg_set_tag_by_name(msg, name);
else
log_msg_clear_tag_by_name(msg, name);
test_msg("%s tag %d %s\n", set ? "Setting" : "Clearing", i, name);
if (set ^ log_msg_is_tag_by_id(msg, i))
test_fail("Tag is %sset now (by id) %d\n", set ? "not " : "", i);
if (set && i < sizeof(gulong) * 8 && msg->num_tags != 0)
test_fail("Small IDs are set which should be stored in-line but num_tags is non-zero");
g_free(name);
}
}
log_msg_unref(msg);
}
void
test_rule_action_message_tag(const gchar *pattern, gint timeout, gint ndx, const gchar *tag, gboolean set)
{
LogMessage *msg = log_msg_new_empty();
gboolean found, result;
PDBInput input;
log_msg_set_value(msg, LM_V_MESSAGE, pattern, strlen(pattern));
log_msg_set_value(msg, LM_V_PROGRAM, "prog2", 5);
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PID, MYPID, strlen(MYPID));
msg->timestamps[LM_TS_STAMP].tv_sec = msg->timestamps[LM_TS_RECVD].tv_sec;
result = pattern_db_process(patterndb, PDB_INPUT_WRAP_MESSAGE(&input, msg));
if (timeout)
timer_wheel_set_time(patterndb->timer_wheel, timer_wheel_get_time(patterndb->timer_wheel) + timeout + 5);
if (ndx >= messages->len)
{
test_fail("Expected the %d. message, but no such message was returned by patterndb\n", ndx);
goto exit;
}
found = log_msg_is_tag_by_name((LogMessage *) g_ptr_array_index(messages, ndx), tag);
if (set ^ found)
test_fail("Tag '%s' is %sset for pattern '%s' (%d), index %d\n", tag, found ? "" : "not ", pattern, !!result, ndx);
exit:
log_msg_unref(msg);
test_clean_state();
}
void
test_filters(gboolean not)
{
LogMessage *msg = log_msg_new_empty();
FilterExprNode *f = filter_tags_new(NULL);
guint i;
GList *l = NULL;
test_msg("=== filter tests %s===\n", not ? "not " : "");
for (i = 1; i < FILTER_TAGS; i += 3)
l = g_list_prepend(l, get_tag_by_id(i));
filter_tags_add(f, l);
f->comp = not;
for (i = 0; i < FILTER_TAGS; i++)
{
test_msg("Testing filter, message has tag %d\n", i);
log_msg_set_tag_by_id(msg, i);
if (((i % 3 == 1) ^ filter_expr_eval(f, msg)) ^ not)
test_fail("Failed to match message by tag %d\n", i);
test_msg("Testing filter, message no tag\n");
log_msg_clear_tag_by_id(msg, i);
if (filter_expr_eval(f, msg) ^ not)
test_fail("Failed to match message with no tags\n");
}
filter_expr_unref(f);
log_msg_unref(msg);
}
/*
* NOTE: suppress_lock must be held.
*/
static void
log_writer_last_msg_flush(LogWriter *self)
{
LogMessage *m;
LogPathOptions path_options = LOG_PATH_OPTIONS_INIT;
gchar buf[1024];
gssize len;
const gchar *p;
msg_debug("Suppress timer elapsed, emitting suppression summary",
NULL);
m = log_msg_new_empty();
m->timestamps[LM_TS_STAMP] = m->timestamps[LM_TS_RECVD];
m->pri = self->last_msg->pri;
m->flags = LF_INTERNAL | LF_LOCAL;
p = log_msg_get_value(self->last_msg, LM_V_HOST, &len);
log_msg_set_value(m, LM_V_HOST, p, len);
p = log_msg_get_value(self->last_msg, LM_V_PROGRAM, &len);
log_msg_set_value(m, LM_V_PROGRAM, p, len);
len = g_snprintf(buf, sizeof(buf), "Last message '%.20s' repeated %d times, suppressed by syslog-ng on %s",
log_msg_get_value(self->last_msg, LM_V_MESSAGE, NULL),
self->last_msg_count,
get_local_hostname(NULL));
log_msg_set_value(m, LM_V_MESSAGE, buf, len);
path_options.ack_needed = FALSE;
log_queue_push_tail(self->queue, m, &path_options);
log_writer_last_msg_release(self);
}
void
test_rule_value_without_clean(const gchar *program, const gchar *pattern,
const gchar *name, const gchar *value)
{
gboolean result;
LogMessage *msg = log_msg_new_empty();
gboolean found = FALSE;
const gchar *val;
gssize len;
PDBInput input;
log_msg_set_value(msg, LM_V_MESSAGE, pattern, strlen(pattern));
log_msg_set_value(msg, LM_V_PROGRAM, program, 5);
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PID, MYPID, strlen(MYPID));
result = pattern_db_process(patterndb, PDB_INPUT_WRAP_MESSAGE(&input, msg));
val = log_msg_get_value(msg, log_msg_get_value_handle(name), &len);
if (value)
found = strcmp(val, value) == 0;
if (!!value ^ (len > 0))
test_fail("Value '%s' is %smatching for pattern '%s' (%d)\n", name, found ? "" : "not ", pattern, !!result);
log_msg_unref(msg);
}
static LogMessage *
copy_str_into_log_message(const gchar *message)
{
LogMessage *msg = log_msg_new_empty();
log_msg_set_value(msg, LM_V_MESSAGE, message, -1);
return msg;
}
void test_set_field_not_exist_and_set_literal_string()
{
LogRewrite *test_rewrite = create_rewrite_rule("set(\"value\" value(\"field1\") );");
LogMessage *msg = log_msg_new_empty();
invoke_rewrite_rule(test_rewrite, msg);
assert_msg_field_equals(msg, "field1", "value", -1, ASSERTION_ERROR("Couldn't set message field when it doesn't exists"));
rewrite_teardown(msg);
}
static LogMessage *
_construct_logmsg(const gchar *msg)
{
LogMessage *logmsg;
logmsg = log_msg_new_empty();
log_msg_set_value(logmsg, LM_V_MESSAGE, msg, -1);
return logmsg;
}
static LogMessage *
_construct_msg(const gchar *msg)
{
LogMessage *logmsg;
logmsg = log_msg_new_empty();
log_msg_set_value_by_name(logmsg, "MESSAGE", msg, -1);
return logmsg;
}
static LogMessage *
_generate_new_message_with_timestamp_of_the_triggering_message(LogStamp *msgstamp)
{
LogMessage *genmsg;
genmsg = log_msg_new_empty();
genmsg->flags |= LF_LOCAL;
genmsg->timestamps[LM_TS_STAMP] = *msgstamp;
return genmsg;
}
static int
lua_message_new(lua_State *state)
{
LogMessage *self = log_msg_new_empty();
self->pri = 0;
self->flags |= LF_LOCAL;
return lua_message_create_from_logmsg(state, self);
}
static LogMessage *
construct_merge_base_message(void)
{
LogMessage *msg;
msg = log_msg_new_empty();
log_msg_set_value_by_name(msg, "base", "basevalue", -1);
log_msg_set_tag_by_name(msg, "basetag");
return msg;
}
static LogMessage *
construct_merged_message(const gchar *name, const gchar *value)
{
LogMessage *msg;
msg = log_msg_new_empty();
log_msg_set_value_by_name(msg, name, value, -1);
log_msg_set_tag_by_name(msg, "mergedtag");
return msg;
}
static void
test_rcptid_is_automatically_assigned_to_a_newly_created_log_message(void)
{
LogMessage *msg;
setup_rcptid_test();
msg = log_msg_new_empty();
assert_guint64(msg->rcptid, 1, "rcptid is not automatically set");
log_msg_unref(msg);
teardown_rcptid_test();
}
static AckRecord *
ack_record_new()
{
AckRecord *self = g_new0(AckRecord, 1);
self->init = _init;
self->deinit = _deinit;
self->ack_message = _ack_message;
self->original = log_msg_new_empty();
self->original->ack_func = self->ack_message;
self->original->ack_record = self;
self->path_options.ack_needed = TRUE;
return self;
}
static gboolean
__handle_message(JournalReader *self)
{
LogMessage *msg = log_msg_new_empty();
msg->pri = self->options->default_pri;
gpointer args[] = {msg, self->options};
journald_foreach_data(self->journal, __handle_data, args);
__set_message_timestamp(self, msg);
log_source_post(&self->super, msg);
return log_source_free_to_send(&self->super);
}
static LogMessage *
_construct_message_with_nvpair(const gchar *program, const gchar *message, const gchar *name, const gchar *value)
{
LogMessage *msg = log_msg_new_empty();
log_msg_set_value(msg, LM_V_MESSAGE, message, strlen(message));
log_msg_set_value(msg, LM_V_PROGRAM, program, strlen(program));
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PID, MYPID, strlen(MYPID));
if (name)
log_msg_set_value_by_name(msg, name, value, -1);
msg->timestamps[LM_TS_STAMP].tv_sec = msg->timestamps[LM_TS_RECVD].tv_sec;
return msg;
}
static gboolean
_load_queue(QDisk *self, GQueue *q, gint64 q_ofs, gint32 q_len, gint32 q_count)
{
GString *serialized;
SerializeArchive *sa;
gint i;
if (q_ofs)
{
gssize read_len;
serialized = g_string_sized_new(q_len);
g_string_set_size(serialized, q_len);
read_len = pread(self->fd, serialized->str, q_len, q_ofs);
if (read_len < 0 || read_len != q_len)
{
msg_error("Error reading in-memory buffer from disk-queue file",
evt_tag_str("filename", self->filename),
read_len < 0 ? evt_tag_errno("error", errno) : evt_tag_str("error", "short read"));
g_string_free(serialized, TRUE);
return FALSE;
}
sa = serialize_string_archive_new(serialized);
for (i = 0; i < q_count; i++)
{
LogMessage *msg;
msg = log_msg_new_empty();
if (log_msg_deserialize(msg, sa))
{
g_queue_push_tail(q, msg);
/* we restore the queue without ACKs */
g_queue_push_tail(q, GINT_TO_POINTER(0x80000000));
}
else
{
msg_error("Error reading message from disk-queue file (maybe currupted file) some messages will be lost",
evt_tag_str("filename", self->filename),
evt_tag_int("lost messages", q_count - i));
log_msg_unref(msg);
break;
}
}
g_string_free(serialized, TRUE);
serialize_archive_free(sa);
}
return TRUE;
}
static void
testcase(gchar *msg, gchar *timezone, gchar *format, gchar *expected)
{
LogTemplate *templ;
LogMessage *logmsg;
LogParser *parser;
gboolean success;
GString *res = g_string_sized_new(128);
parser = date_parser_new (configuration);
if (format != NULL) date_parser_set_format(parser, format);
if (timezone != NULL) date_parser_set_timezone(parser, timezone);
log_pipe_init(&parser->super);
logmsg = log_msg_new_empty();
logmsg->timestamps[LM_TS_RECVD].tv_sec = 1451473200; /* Dec 30 2015 */
log_msg_set_value(logmsg, log_msg_get_value_handle("MESSAGE"), msg, -1);
success = log_parser_process(parser, &logmsg, NULL, log_msg_get_value(logmsg, LM_V_MESSAGE, NULL), -1);
if (!success && expected)
{
fprintf(stderr, "unable to parse format=%s msg=%s\n", format, msg);
exit(1);
}
else if (success && !expected)
{
fprintf(stderr, "successfully parsed but expected failure, format=%s msg=%s\n", format, msg);
exit(1);
}
else if (expected)
{
/* Convert to ISODATE */
templ = compile_template("${ISODATE}", FALSE);
log_template_format(templ, logmsg, NULL, LTZ_LOCAL, -1, NULL, res);
assert_nstring(res->str, res->len, expected, strlen(expected),
"incorrect date parsed msg=%s format=%s",
msg, format);
log_template_unref(templ);
}
g_string_free(res, TRUE);
log_pipe_unref(&parser->super);
log_msg_unref(logmsg);
return;
}
static void
test_log_msg_get_value_with_time_related_macro(void)
{
LogMessage *msg;
gssize value_len;
NVHandle handle;
const char *date_value;
msg = log_msg_new_empty();
msg->timestamps[LM_TS_STAMP].tv_sec = 1389783444;
handle = log_msg_get_value_handle("ISODATE");
date_value = log_msg_get_value(msg, handle, &value_len);
assert_string(date_value, "2014-01-15T10:57:23-00:00", "ISODATE macro value does not match!");
log_msg_unref(msg);
}
void
test_pattern(const gchar *pattern, const gchar *rule, gboolean match)
{
gboolean result;
LogMessage *msg = log_msg_new_empty();
static LogTemplate *templ;
GString *res = g_string_sized_new(128);
static TimeZoneInfo *tzinfo = NULL;
PDBInput input;
if (!tzinfo)
tzinfo = time_zone_info_new(NULL);
if (!templ)
{
templ = log_template_new(configuration, "dummy");
log_template_compile(templ, "$TEST", NULL);
}
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PROGRAM, "test", strlen(MYHOST));
log_msg_set_value(msg, LM_V_MESSAGE, pattern, strlen(pattern));
result = pattern_db_process(patterndb, PDB_INPUT_WRAP_MESSAGE(&input, msg));
log_template_format(templ, msg, NULL, LTZ_LOCAL, 0, NULL, res);
if (strcmp(res->str, pattern) == 0)
{
test_msg("Rule: '%s' Value '%s' is inserted into $TEST res:(%s)\n", rule, pattern, res->str);
}
if ((match && !result) || (!match && result))
{
test_fail("FAIL: Value '%s' is %smatching for pattern '%s' \n", rule, !!result ? "" : "not ", pattern);
}
else
{
test_msg("Value '%s' is %smatching for pattern '%s' \n", rule, !!result ? "" : "not ", pattern);
}
g_string_free(res, TRUE);
log_msg_unref(msg);
}
LogMessage *
create_message_with_fields(const char *field_name, ...)
{
va_list args;
const char* arg;
LogMessage *msg = log_msg_new_empty();
arg = field_name;
va_start(args, field_name);
while (arg != NULL)
{
NVHandle handle = log_msg_get_value_handle(arg);
arg = va_arg(args, char*);
log_msg_set_value(msg, handle, arg, -1);
arg = va_arg(args, char*);
}
va_end(args);
return msg;
}
static LogMessage *
parse_kv_into_log_message_no_check(const gchar *kv)
{
LogMessage *msg;
LogPathOptions path_options = LOG_PATH_OPTIONS_INIT;
LogParser *cloned_parser;
cloned_parser = (LogParser *) log_pipe_clone(&kv_parser->super);
msg = log_msg_new_empty();
if (!log_parser_process(cloned_parser, &msg, &path_options, kv, strlen(kv)))
{
log_msg_unref(msg);
log_pipe_unref(&cloned_parser->super);
return NULL;
}
log_pipe_unref(&cloned_parser->super);
return msg;
}
static void
log_writer_last_msg_flush(LogWriter *self)
{
LogMessage *m;
LogPathOptions path_options = LOG_PATH_OPTIONS_INIT;
gchar hostname[256];
gchar buf[1024];
gssize len;
const gchar *p;
msg_debug("Suppress timer elapsed, emitting suppression summary",
NULL);
getlonghostname(hostname, sizeof(hostname));
m = log_msg_new_empty();
m->timestamps[LM_TS_STAMP] = m->timestamps[LM_TS_RECVD];
m->pri = self->last_msg->pri;
m->flags = LF_INTERNAL | LF_LOCAL;
p = log_msg_get_value(self->last_msg, LM_V_HOST, &len);
log_msg_set_value(m, LM_V_HOST, p, len);
p = log_msg_get_value(self->last_msg, LM_V_PROGRAM, &len);
log_msg_set_value(m, LM_V_PROGRAM, p, len);
len = g_snprintf(buf, sizeof(buf), "Last message '%.20s' repeated %d times, supressed by syslog-ng on %s",
log_msg_get_value(self->last_msg, LM_V_MESSAGE, NULL),
self->last_msg_count,
hostname);
log_msg_set_value(m, LM_V_MESSAGE, buf, len);
path_options.flow_control = FALSE;
if (!log_queue_push_tail(self->queue, m, &path_options))
{
stats_counter_inc(self->dropped_messages);
msg_debug("Destination queue full, dropping suppressed message",
evt_tag_int("queue_len", log_queue_get_length(self->queue)),
evt_tag_int("mem_fifo_size", self->options->mem_fifo_size),
NULL);
log_msg_drop(m, &path_options);
}
log_writer_last_msg_release(self);
}
static void
testcase(gchar *msg, goffset offset, gchar *timezone, gchar *format, gchar *expected)
{
LogTemplate *templ;
LogMessage *logmsg;
NVTable *nvtable;
GlobalConfig *cfg = cfg_new (0x302);
LogParser *parser = date_parser_new (cfg);
gboolean success;
const gchar *context_id = "test-context-id";
GString *res = g_string_sized_new(128);
date_parser_set_offset(parser, offset);
if (format != NULL) date_parser_set_format(parser, format);
if (timezone != NULL) date_parser_set_timezone(parser, timezone);
parse_options.flags = 0;
logmsg = log_msg_new_empty();
logmsg->timestamps[LM_TS_RECVD].tv_sec = 1438793384; /* Wed Aug 5 2015 */
log_msg_set_value(logmsg, log_msg_get_value_handle("MESSAGE"), msg, -1);
nvtable = nv_table_ref(logmsg->payload);
success = log_parser_process(parser, &logmsg, NULL, log_msg_get_value(logmsg, LM_V_MESSAGE, NULL), -1);
nv_table_unref(nvtable);
if (!success)
{
fprintf(stderr, "unable to parse offset=%d format=%s msg=%s\n", offset, format, msg);
exit(1);
}
/* Convert to ISODATE */
templ = compile_template("${ISODATE}", FALSE);
log_template_format(templ, logmsg, NULL, LTZ_LOCAL, 999, context_id, res);
assert_nstring(res->str, res->len, expected, strlen(expected),
"incorrect date parsed msg=%s offset=%d format=%s",
msg, offset, format);
log_template_unref(templ);
g_string_free(res, TRUE);
log_pipe_unref(&parser->super);
log_msg_unref(logmsg);
return;
}
void
test_msg_tags()
{
LogMessage *msg = log_msg_new_empty();
gchar *name;
gint i, set;
test_msg("=== LogMessage tests ===\n");
for (set = 1; set != -1; set--)
{
for (i = NUM_TAGS; i > -1; i--)
{
name = get_tag_by_id(i);
if (set)
log_msg_set_tag_by_name(msg, name);
else
log_msg_clear_tag_by_name(msg, name);
test_msg("%s tag %d %s\n", set ? "Setting" : "Clearing", i, name);
if (set ^ log_msg_is_tag_by_id(msg, i))
test_fail("Tag is %sset now (by id) %d\n", set ? "not " : "", i);
g_free(name);
}
for (i = 0; i < NUM_TAGS; i++)
{
name = get_tag_by_id(i);
test_msg("Checking tag %d %s\n", i, name);
if (set ^ log_msg_is_tag_by_id(msg, i))
test_fail("Tag is %sset (by id) %d\n", set ? "not " : "", i);
if (set ^ log_msg_is_tag_by_name(msg, name))
test_fail("Tag is %sset (by name) %s\n", set ? "not " : "", name);
g_free(name);
}
}
log_msg_unref(msg);
}
void
test_rule_tag(const gchar *pattern, const gchar *tag, gboolean set)
{
LogMessage *msg = log_msg_new_empty();
gboolean found, result;
PDBInput input;
log_msg_set_value(msg, LM_V_MESSAGE, pattern, strlen(pattern));
log_msg_set_value(msg, LM_V_PROGRAM, "prog2", 5);
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PID, MYPID, strlen(MYPID));
result = pattern_db_process(patterndb, PDB_INPUT_WRAP_MESSAGE(&input, msg));
found = log_msg_is_tag_by_name(msg, tag);
if (set ^ found)
test_fail("Tag '%s' is %sset for pattern '%s' (%d)\n", tag, found ? "" : "not ", pattern, !!result);
log_msg_unref(msg);
test_clean_state();
}
static gpointer
_threaded_feed(gpointer args)
{
LogQueue *q = args;
gint i;
LogPathOptions path_options = LOG_PATH_OPTIONS_INIT;
LogMessage *msg, *tmpl;
GTimeVal start, end;
glong diff;
iv_init();
/* emulate main loop for LogQueue */
main_loop_worker_thread_start(NULL);
tmpl = log_msg_new_empty();
g_get_current_time(&start);
for (i = 0; i < MESSAGES_PER_FEEDER; i++)
{
msg = log_msg_clone_cow(tmpl, &path_options);
log_msg_add_ack(msg, &path_options);
msg->ack_func = test_ack;
log_queue_push_tail(q, msg, &path_options);
if ((i & 0xFF) == 0)
main_loop_worker_invoke_batch_callbacks();
}
main_loop_worker_invoke_batch_callbacks();
g_get_current_time(&end);
diff = g_time_val_diff(&end, &start);
g_static_mutex_lock(&tlock);
sum_time += diff;
g_static_mutex_unlock(&tlock);
log_msg_unref(tmpl);
main_loop_worker_thread_stop();
iv_deinit();
return NULL;
}
static LogMessage *
parse_geoip_into_log_message_no_check(const gchar *input)
{
LogMessage *msg;
LogPathOptions path_options = LOG_PATH_OPTIONS_INIT;
LogParser *cloned_parser;
gboolean success;
cloned_parser = (LogParser *) log_pipe_clone(&geoip_parser->super);
log_pipe_init(&cloned_parser->super);
msg = log_msg_new_empty();
log_msg_set_value(msg, LM_V_MESSAGE, input, -1);
success = log_parser_process_message(cloned_parser, &msg, &path_options);
if (!success)
{
log_msg_unref(msg);
msg = NULL;
}
log_pipe_deinit(&cloned_parser->super);
log_pipe_unref(&cloned_parser->super);
return msg;
}
void
test_pattern(const gchar *pattern, const gchar *rule, gboolean match)
{
gboolean result;
LogMessage *msg = log_msg_new_empty();
log_msg_set_value(msg, LM_V_HOST, MYHOST, strlen(MYHOST));
log_msg_set_value(msg, LM_V_PROGRAM, "test", strlen(MYHOST));
log_msg_set_value(msg, LM_V_MESSAGE, pattern, strlen(pattern));
result = pattern_db_process(patterndb, msg);
if (match)
{
assert_true(result, "Value '%s' is not matching for pattern '%s'\n", rule, pattern);
}
else
{
assert_false(result, "Value '%s' is matching for pattern '%s'\n", rule, pattern);
}
log_msg_unref(msg);
}
