Example #1
0
void
crm_enable_blackbox(int nsig)
{
    if (blackbox_file_prefix == NULL) {
        pid_t pid = getpid();

        blackbox_file_prefix = malloc(NAME_MAX);
        snprintf(blackbox_file_prefix, NAME_MAX, "%s/%s-%d", CRM_BLACKBOX_DIR, crm_system_name,
                 pid);
    }

    if (qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
        qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
        qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);      /* Setting the size seems to disable it */

        crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);

        /* Save to disk on abnormal termination */
        crm_signal(SIGSEGV, crm_trigger_blackbox);
        crm_signal(SIGABRT, crm_trigger_blackbox);
        crm_signal(SIGILL,  crm_trigger_blackbox);
        crm_signal(SIGBUS,  crm_trigger_blackbox);

        crm_update_callsites();

        blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
        qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
        crm_trace("Trigger: %d is %d %d", blackbox_trigger,
                  qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);

        crm_update_callsites();
    }
}
Example #2
0
END_TEST

#ifdef HAVE_PTHREAD_SETSCHEDPARAM
START_TEST(test_threaded_logging_bad_sched_params)
{
	int32_t t;
	int32_t rc;

	qb_log_init("test", LOG_USER, LOG_EMERG);
	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);

	t = qb_log_custom_open(_test_logger, NULL, NULL, NULL);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			       QB_LOG_FILTER_FILE, "*", LOG_INFO);
	ck_assert_int_eq(rc, 0);
	qb_log_format_set(t, "%b");
	rc = qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_ctl(t, QB_LOG_CONF_THREADED, QB_TRUE);
	ck_assert_int_eq(rc, 0);

#if defined(SCHED_RR)
#define QB_SCHED SCHED_RR
#elif defined(SCHED_FIFO)
#define QB_SCHED SCHED_FIFO
#else
#define QB_SCHED (-1)
#endif
	rc = qb_log_thread_priority_set(QB_SCHED, -1);
	ck_assert_int_eq(rc, 0);

	rc = qb_log_thread_start();
	ck_assert_int_ne(rc, 0);
	qb_log_fini();
}
Example #3
0
END_TEST
#endif

START_TEST(test_extended_information)
{
	int32_t t;
	int32_t rc;
	int extended;

	qb_log_init("test", LOG_USER, LOG_DEBUG);
	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);

	t = qb_log_custom_open(_test_logger, NULL, NULL, NULL);
	_ck_assert_int(t, >, QB_LOG_STDOUT);
	qb_log_format_set(t, "%b");
	rc = qb_log_filter_fn_set(NULL);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL, QB_LOG_FILTER_FILE,
			       "*", LOG_TRACE);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL, QB_LOG_FILTER_FORMAT,
			       "*", LOG_TRACE);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FORMAT,
			       "*", LOG_TRACE);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);
	ck_assert_int_eq(rc, 0);

	for (extended = QB_FALSE; extended <= QB_TRUE; ++extended) {
		rc = qb_log_ctl(t, QB_LOG_CONF_EXTENDED, extended);
		ck_assert_int_eq(rc, 0);

		num_msgs = 0;

		memset(test_buf, 0, sizeof(test_buf));
		qb_log(LOG_ERR, "message with no extended information");
		ck_assert_str_eq(test_buf, "message with no extended information");

		memset(test_buf, 0, sizeof(test_buf));
		qb_log(LOG_ERR, "message with empty extended information "QB_XS);
		ck_assert_str_eq(test_buf, "message with empty extended information ");

		memset(test_buf, 0, sizeof(test_buf));
		qb_log(LOG_ERR, QB_XS" message with only extended information");
		ck_assert_str_eq(test_buf, extended?
				 "| message with only extended information" : "");

		memset(test_buf, 0, sizeof(test_buf));
		qb_log(LOG_ERR, "message with extended information "QB_XS" (namely this)");
		ck_assert_str_eq(test_buf, extended?
				 "message with extended information | (namely this)"
				 : "message with extended information ");

		ck_assert_int_eq(num_msgs, (extended? 4 : 3));
	}
	qb_log_fini();
}
Example #4
0
END_TEST

START_TEST(test_threaded_logging)
{
	int32_t t;
	int32_t rc;

	qb_log_init("test", LOG_USER, LOG_EMERG);
	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);

	t = qb_log_custom_open(_test_logger, NULL, NULL, NULL);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			       QB_LOG_FILTER_FILE, "*", LOG_INFO);
	ck_assert_int_eq(rc, 0);
	qb_log_format_set(t, "%b");
	rc = qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);
	ck_assert_int_eq(rc, 0);
	rc = qb_log_ctl(t, QB_LOG_CONF_THREADED, QB_TRUE);
	ck_assert_int_eq(rc, 0);
	qb_log_thread_start();

	memset(test_buf, 0, sizeof(test_buf));
	test_priority = 0;
	num_msgs = 0;

	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);
	qb_log(LOG_INFO, "Yoda how old are you? - %d", __LINE__);

	qb_log_fini();

	ck_assert_int_eq(num_msgs, 10);
}
Example #5
0
END_TEST

START_TEST(test_log_enable)
{
	int32_t t;
	int32_t state;

	qb_log_init("test", LOG_USER, LOG_DEBUG);
	state = qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_STATE_GET, 0);
	ck_assert_int_eq(state, QB_LOG_STATE_ENABLED);
	state = qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0);
	ck_assert_int_eq(state, QB_LOG_STATE_DISABLED);
	state = qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0);
	ck_assert_int_eq(state, QB_LOG_STATE_DISABLED);

	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);
	state = qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_STATE_GET, 0);
	ck_assert_int_eq(state, QB_LOG_STATE_DISABLED);

	t = qb_log_custom_open(_test_logger, NULL, NULL, NULL);
	qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);

	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FILE, "*", LOG_DEBUG);
	qb_log_format_set(t, "%b");

	qb_log(LOG_DEBUG, "Hello");
	ck_assert_str_eq(test_buf, "Hello");

	num_msgs = 0;
	qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_FALSE);
	qb_log(LOG_DEBUG, "Goodbye");
	ck_assert_int_eq(num_msgs, 0);
	qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);
	qb_log(LOG_DEBUG, "Hello again");
	ck_assert_int_eq(num_msgs, 1);
	ck_assert_str_eq(test_buf, "Hello again");
}
Example #6
0
void
crm_enable_blackbox(int nsig)
{
    if (blackbox_file_prefix == NULL) {
        pid_t pid = getpid();

        blackbox_file_prefix = malloc(NAME_MAX);
        snprintf(blackbox_file_prefix, NAME_MAX, "%s/%s-%d", CRM_BLACKBOX_DIR, crm_system_name,
                 pid);
    }

    if (qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
        qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
        qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);      /* Setting the size seems to disable it */

        crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);
        crm_signal(SIGSEGV, crm_trigger_blackbox);
        crm_update_callsites();

        /* Original meanings from signal(7) 
         *
         * Signal       Value     Action   Comment
         * SIGTRAP        5        Core    Trace/breakpoint trap
         *
         * Our usage is as similar as possible
         */
        mainloop_add_signal(SIGTRAP, crm_trigger_blackbox);

        blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
        qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
        crm_info("Trigger: %d is %d %d", blackbox_trigger,
                 qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);

        crm_update_callsites();
    }
}
Example #7
0
int32_t
main(int32_t argc, char *argv[])
{
	const char *options = "vhteobdf:";
	int32_t opt;
	int32_t tracer;
	int32_t do_stderr = QB_FALSE;
	int32_t do_stdout = QB_FALSE;
	int32_t do_dump_blackbox = QB_FALSE;
	char *logfile = NULL;
	int32_t log_fd = -1;

	while ((opt = getopt(argc, argv, options)) != -1) {
		switch (opt) {
		case 'd':
			do_dump_blackbox = QB_TRUE;
			break;
		case 't':
			do_threaded = QB_TRUE;
			break;
		case 'e':
			do_stderr = QB_TRUE;
			break;
		case 'o':
			do_stdout = QB_TRUE;
			break;
		case 'b':
			do_blackbox = QB_TRUE;
			break;
		case 'f':
			logfile = optarg;
			break;
		case 'v':
			_log_priority++;
			break;
		case 'h':
		default:
			show_usage(argv[0]);
			exit(0);
			break;
		}
	}

	if (do_dump_blackbox) {
		qb_log_blackbox_print_from_file("simple-log.fdata");
		exit(0);
	}

	signal(SIGSEGV, sigsegv_handler);

	qb_log_init("simple-log", LOG_USER, LOG_INFO);
	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_THREADED, do_threaded);
	qb_log_tags_stringify_fn_set(my_tags_stringify);

	if (do_stderr) {
		qb_log_filter_fn_set(m_filter);
		qb_log_format_set(QB_LOG_STDERR, "[%p] %4g: %f:%l %b");
		qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);

		tracer = qb_log_custom_open(trace_logger, NULL, NULL, NULL);
		qb_log_ctl(tracer, QB_LOG_CONF_ENABLED, QB_TRUE);
		qb_log_format_set(tracer, "%4g: %n() %b");
		qb_log_filter_ctl2(tracer, QB_LOG_FILTER_ADD,
				   QB_LOG_FILTER_FILE, __FILE__,
				   LOG_TRACE, 200);
	}
	if (do_stdout) {
		qb_log_filter_ctl2(QB_LOG_STDOUT, QB_LOG_FILTER_ADD,
				   QB_LOG_FILTER_FILE, __FILE__,
				   LOG_ALERT, QB_MIN(LOG_DEBUG, _log_priority));
		qb_log_format_set(QB_LOG_STDOUT, "[%p] %4g: %f:%l %b");
		qb_log_ctl(QB_LOG_STDOUT, QB_LOG_CONF_ENABLED, QB_TRUE);
	}
	if (do_blackbox) {
		qb_log_filter_ctl(QB_LOG_BLACKBOX, QB_LOG_FILTER_ADD,
				  QB_LOG_FILTER_FILE, "*", LOG_DEBUG);
		qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 4096);
		qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_THREADED, QB_FALSE);
		qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);
	}
	if (logfile) {
		log_fd = qb_log_file_open(logfile);
		qb_log_filter_ctl(log_fd, QB_LOG_FILTER_ADD,
				  QB_LOG_FILTER_FILE, __FILE__, _log_priority);
		qb_log_format_set(log_fd, "[%N] %t %n() [%p] %b");
		qb_log_ctl(log_fd, QB_LOG_CONF_THREADED, do_threaded);
		qb_log_ctl(log_fd, QB_LOG_CONF_ENABLED, QB_TRUE);
	}
	if (do_threaded) {
		qb_log_thread_start();
	}
	qb_log(LOG_DEBUG, "hello");
	qb_log(LOG_INFO, "this is an info");
	qb_log(LOG_NOTICE, "hello - notice?");
	func_one();
	func_two();

	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);

	qb_log(LOG_WARNING, "no syslog");
	qb_log(LOG_ERR, "no syslog");

#if 0
	// test blackbox
	logfile = NULL;
	logfile[5] = 'a';
#endif
	if (do_blackbox) {
		qb_log_blackbox_write_to_file("simple-log.fdata");
		qb_log_blackbox_print_from_file("simple-log.fdata");
		qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
	}
	qb_log_fini();
	return 0;
}
Example #8
0
END_TEST

START_TEST(test_log_basic)
{
	int32_t t;
	int32_t rc;

	qb_log_init("test", LOG_USER, LOG_EMERG);
	qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);

	t = qb_log_custom_open(_test_logger, NULL, NULL, NULL);
	rc = qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FORMAT, "Angus", LOG_WARNING);
	ck_assert_int_eq(rc, 0);
	qb_log_format_set(t, "%b");
	rc = qb_log_ctl(t, QB_LOG_CONF_ENABLED, QB_TRUE);
	ck_assert_int_eq(rc, 0);

	/* captures last log */
	memset(test_buf, 0, sizeof(test_buf));
	test_priority = 0;
	num_msgs = 0;

	/*
	 * test filtering by format
	 */
	qb_log(LOG_INFO, "Hello Angus, how are you?");
	qb_log(LOG_WARNING, "Hello Steven, how are you?");
	qb_log(LOG_ERR, "Hello Andrew, how are you?");
	qb_log(LOG_ERR, "Hello Angus, how are you?");
	qb_log(LOG_EMERG, "Hello Anna, how are you?");
	ck_assert_int_eq(test_priority, LOG_ERR);
	ck_assert_int_eq(num_msgs, 1);
	ck_assert_str_eq(test_buf, "Hello Angus, how are you?");


	/* 
	 * test filtering by file regex
 	 */
	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FORMAT, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FILE_REGEX, "^fakefile*", LOG_DEBUG);

	num_msgs = 0;
	qb_log_from_external_source(__func__, "fakefile_logging", "%s bla", LOG_INFO,
				    56, 0, "filename/lineno");
	qb_log_from_external_source(__func__, "do_not_log_fakefile_logging", "%s bla", LOG_INFO,
				    56, 0, "filename/lineno");
	ck_assert_int_eq(num_msgs, 1);

	/* 
	 * test filtering by format regex
 	 */
	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FORMAT, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FORMAT_REGEX, "^one", LOG_WARNING);

	num_msgs = 0;
	qb_log(LOG_INFO, "one two three");
	qb_log(LOG_ERR, "testing one two three");
	qb_log(LOG_WARNING, "one two three");
	qb_log(LOG_ERR, "one two three");
	qb_log(LOG_EMERG, "one two three");
	ck_assert_int_eq(num_msgs, 3);

	/*
	 * test filtering by function and regex
	 */
	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FILE, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FUNCTION_REGEX, "^log_.*please", LOG_WARNING);

	num_msgs = 0;
	qb_log(LOG_ERR, "try if you: log_it_please()");
	log_it_please();
	ck_assert_int_eq(num_msgs, 3);

	qb_log_filter_ctl(t, QB_LOG_FILTER_REMOVE,
			  QB_LOG_FILTER_FUNCTION_REGEX, "log_it_please", LOG_WARNING);

	/*
	 * test filtering by function
	 */
	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FILE, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FUNCTION, "log_it_please", LOG_WARNING);

	num_msgs = 0;
	qb_log(LOG_ERR, "try if you: log_it_please()");
	log_it_please();
	ck_assert_int_eq(num_msgs, 3);

	qb_log_filter_ctl(t, QB_LOG_FILTER_REMOVE,
			  QB_LOG_FILTER_FUNCTION, "log_it_please", LOG_WARNING);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FUNCTION, __func__, LOG_DEBUG);

	num_msgs = 0;
	log_it_please();
	ck_assert_int_eq(num_msgs, 0);
	qb_log(LOG_DEBUG, "try if you: log_it_please()");
	ck_assert_int_eq(num_msgs, 1);

	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FILE, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FUNCTION,
			  "log_also,log_and_this_too",
			  LOG_DEBUG);
	num_msgs = 0;
	log_also();
	log_and_this_too();
	ck_assert_int_eq(num_msgs, 2);

	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FILE, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FILE, "fakefile.c,"__FILE__",otherfakefile", LOG_DEBUG);
	/*
	 * make sure we can pass in a null filename or function name.
	 */
	qb_log_from_external_source(__func__, NULL, "%s", LOG_INFO,
				    __LINE__, 0, "null filename");
	qb_log_from_external_source(NULL, __FILE__, "%s", LOG_INFO,
				    __LINE__, 0, "null function");

	/* check same file/lineno logs with different formats work
	 */
	num_msgs = 0;
	qb_log_from_external_source(__func__, __FILE__, "%s bla", LOG_INFO,
				    56, 0, "filename/lineno");
	ck_assert_int_eq(num_msgs, 1);
	ck_assert_str_eq(test_buf, "filename/lineno bla");

	num_msgs = 0;
	qb_log_from_external_source(__func__, __FILE__, "%s", LOG_INFO,
				    56, 0, "same filename/lineno");
	ck_assert_int_eq(num_msgs, 1);
	ck_assert_str_eq(test_buf, "same filename/lineno");

	/* check filtering works on same file/lineno but different
	 * log level.
	 */
	qb_log_filter_ctl(t, QB_LOG_FILTER_CLEAR_ALL,
			  QB_LOG_FILTER_FILE, "*", LOG_TRACE);
	qb_log_filter_ctl(t, QB_LOG_FILTER_ADD,
			  QB_LOG_FILTER_FILE, __FILE__, LOG_INFO);

	num_msgs = 0;
	qb_log_from_external_source(__func__, __FILE__,
				    "same filename/lineno, this level %d",
				    LOG_INFO, 56, 0, LOG_INFO);
	ck_assert_int_eq(num_msgs, 1);
	ck_assert_str_eq(test_buf, "same filename/lineno, this level 6");

	num_msgs = 0;
	qb_log_from_external_source(__func__, __FILE__,
				    "same filename/lineno, this level %d",
				    LOG_DEBUG, 56, 0, LOG_DEBUG);
	ck_assert_int_eq(num_msgs, 0);
}