[thirdparty/systemd.git] / src / test / test-log.c

/* SPDX-License-Identifier: LGPL-2.1-or-later */

#include "format-util.h"
#include "iovec-util.h"
#include "iovec-wrapper.h"
#include "log.h"
#include "log-context.h"
#include "process-util.h"
#include "string-util.h"
#include "strv.h"
#include "tests.h"

#define X10(x) x x x x x x x x x x
#define X100(x) X10(X10(x))
#define X1000(x) X100(X10(x))

static int fail_with_EINVAL(void) {
        assert_return(false, -EINVAL);
        return 0;
}

static void test_assert_return_is_critical(void) {
        SAVE_ASSERT_RETURN_IS_CRITICAL;

        log_set_assert_return_is_critical(false);
        assert_se(fail_with_EINVAL() == -EINVAL);

        log_set_assert_return_is_critical(true);
        ASSERT_RETURN_IS_CRITICAL(false, assert_se(fail_with_EINVAL() == -EINVAL));
        assert_se(log_get_assert_return_is_critical() == true);
        ASSERT_RETURN_EXPECTED(assert_se(fail_with_EINVAL() == -EINVAL));
        assert_se(log_get_assert_return_is_critical() == true);
        ASSERT_RETURN_EXPECTED_SE(fail_with_EINVAL() == -EINVAL);
        assert_se(log_get_assert_return_is_critical() == true);
}

static void test_file(void) {
        log_info("__FILE__: %s", __FILE__);
        log_info("RELATIVE_SOURCE_PATH: %s", RELATIVE_SOURCE_PATH);
        log_info("PROJECT_FILE: %s", PROJECT_FILE);

        assert_se(startswith(__FILE__, RELATIVE_SOURCE_PATH "/"));
}

static void test_log_struct(void) {
        log_struct(LOG_INFO,
                   "MESSAGE=Waldo PID="PID_FMT" (no errno)", getpid_cached(),
                   "SERVICE=piepapo");

        /* The same as above, just using LOG_MESSAGE() and LOG_ITEM(), which is generally recommended */
        log_struct(LOG_INFO,
                   LOG_MESSAGE("Waldo PID="PID_FMT" (no errno)", getpid_cached()),
                   LOG_ITEM("SERVICE=piepapo"));

        log_struct_errno(LOG_INFO, EILSEQ,
                         LOG_MESSAGE("Waldo PID="PID_FMT": %m (normal)", getpid_cached()),
                         LOG_ITEM("SERVICE=piepapo"));

        log_struct_errno(LOG_INFO, SYNTHETIC_ERRNO(EILSEQ),
                         LOG_MESSAGE("Waldo PID="PID_FMT": %m (synthetic)", getpid_cached()),
                         LOG_ITEM("SERVICE=piepapo"));

        log_struct(LOG_INFO,
                   LOG_MESSAGE("Foobar PID="PID_FMT, getpid_cached()),
                   LOG_ITEM("FORMAT_STR_TEST=1=%i A=%c 2=%hi 3=%li 4=%lli 1=%p foo=%s 2.5=%g 3.5=%g 4.5=%Lg",
                            (int) 1, 'A', (short) 2, (long) 3, (long long) 4, (void*) 1, "foo", (float) 2.5f, (double) 3.5, (long double) 4.5),
                   LOG_ITEM("SUFFIX=GOT IT"));
}

static void test_long_lines(void) {
        log_object_internal(LOG_NOTICE,
                            EUCLEAN,
                            X1000("abcd_") ".txt",
                            1000000,
                            X1000("fff") "unc",
                            "OBJECT=",
                            X1000("obj_") "ect",
                            "EXTRA=",
                            X1000("ext_") "tra",
                            "asdfasdf %s asdfasdfa", "foobar");
}

static void test_log_syntax(void) {
        assert_se(log_syntax("unit", LOG_ERR, "filename", 10, EINVAL, "EINVAL: %s: %m", "hogehoge") == -EINVAL);
        assert_se(log_syntax("unit", LOG_ERR, "filename", 10, -ENOENT, "ENOENT: %s: %m", "hogehoge") == -ENOENT);
        assert_se(log_syntax("unit", LOG_ERR, "filename", 10, SYNTHETIC_ERRNO(ENOTTY), "ENOTTY: %s: %m", "hogehoge") == -ENOTTY);
}

static void test_log_context(void) {
        {
                char **strv = STRV_MAKE("FIRST=abc", "SECOND=qrs");

                LOG_CONTEXT_PUSH("THIRD=pfs");
                LOG_CONTEXT_PUSH("FOURTH=def");
                LOG_CONTEXT_PUSH_STRV(strv);
                LOG_CONTEXT_PUSH_STRV(strv);

                /* Test that the log context was set up correctly. The strv we pushed twice should only
                 * result in one log context which is reused. */
                assert_se(log_context_num_contexts() == 3);
                assert_se(log_context_num_fields() == 4);

                /* Test that everything still works with modifications to the log context. */
                test_log_struct();
                test_long_lines();
                test_log_syntax();

                {
                        LOG_CONTEXT_PUSH("FIFTH=123");
                        LOG_CONTEXT_PUSH_STRV(strv);

                        /* Check that our nested fields got added correctly. */
                        assert_se(log_context_num_contexts() == 4);
                        assert_se(log_context_num_fields() == 5);

                        /* Test that everything still works in a nested block. */
                        test_log_struct();
                        test_long_lines();
                        test_log_syntax();
                }

                /* Check that only the fields from the nested block got removed. */
                assert_se(log_context_num_contexts() == 3);
                assert_se(log_context_num_fields() == 4);
        }

        assert_se(log_context_num_contexts() == 0);
        assert_se(log_context_num_fields() == 0);

        {
                _cleanup_(log_context_unrefp) LogContext *ctx = NULL;

                char **strv = STRV_MAKE("SIXTH=ijn", "SEVENTH=PRP");
                assert_se(ctx = log_context_new_strv(strv, /*owned=*/ false));

                assert_se(log_context_num_contexts() == 1);
                assert_se(log_context_num_fields() == 2);

                /* Test that everything still works with a manually configured log context. */
                test_log_struct();
                test_long_lines();
                test_log_syntax();
        }

        {
                char **strv = NULL;

                assert_se(strv = strv_new("ABC", "DEF"));
                LOG_CONTEXT_CONSUME_STRV(strv);

                assert_se(log_context_num_contexts() == 1);
                assert_se(log_context_num_fields() == 2);
        }

        {
                /* Test that everything still works with a mixed strv and iov. */
                struct iovec iov[] = {
                        IOVEC_MAKE_STRING("ABC=def"),
                        IOVEC_MAKE_STRING("GHI=jkl"),
                };
                _cleanup_free_ struct iovec_wrapper *iovw = iovw_new();
                assert_se(iovw);
                assert_se(iovw_consume(iovw, strdup("MNO=pqr"), STRLEN("MNO=pqr") + 1) == 0);

                LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
                LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
                LOG_CONTEXT_CONSUME_IOV(iovw->iovec, iovw->count);
                LOG_CONTEXT_PUSH("STU=vwx");

                assert_se(log_context_num_contexts() == 3);
                assert_se(log_context_num_fields() == 4);

                test_log_struct();
                test_long_lines();
                test_log_syntax();
        }

        {
                LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
                LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
                assert_se(log_context_num_contexts() == 1);
                assert_se(log_context_num_fields() == 1);

                test_log_struct();
                test_long_lines();
                test_log_syntax();
        }

        assert_se(log_context_num_contexts() == 0);
        assert_se(log_context_num_fields() == 0);
}

static void test_log_prefix(void) {
        {
                LOG_SET_PREFIX("ABC");

                test_log_struct();
                test_long_lines();
                test_log_syntax();

                {
                        LOG_SET_PREFIX("QED");

                        test_log_struct();
                        test_long_lines();
                        test_log_syntax();
                }

                test_log_struct();
                test_long_lines();
                test_log_syntax();
        }

        test_log_struct();
        test_long_lines();
        test_log_syntax();
}

int main(int argc, char* argv[]) {
        test_setup_logging(LOG_DEBUG);

        ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(EINVAL)));
        ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(-EINVAL)));
        assert_cc(!IS_SYNTHETIC_ERRNO(EINVAL));
        assert_cc(!IS_SYNTHETIC_ERRNO(-EINVAL));
        ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(0)));
        assert_cc(!IS_SYNTHETIC_ERRNO(0));
        ASSERT_EQ(ERRNO_VALUE(EINVAL), EINVAL);
        ASSERT_EQ(ERRNO_VALUE(SYNTHETIC_ERRNO(-EINVAL)), EINVAL);

        test_assert_return_is_critical();
        test_file();

        assert_se(log_info_errno(SYNTHETIC_ERRNO(EUCLEAN), "foo") == -EUCLEAN);

        for (int target = 0; target < _LOG_TARGET_MAX; target++) {
                log_set_target(target);
                log_open();

                test_log_struct();
                test_long_lines();
                test_log_syntax();
                test_log_context();
                test_log_prefix();
        }

        return 0;
}
Commit	Line	Data
db9ecf05	1	/* SPDX-License-Identifier: LGPL-2.1-or-later */
877d54e9	2
f97b34a6	3	#include "format-util.h"
bd1ae178	4	#include "iovec-util.h"
ea1f3814	5	#include "iovec-wrapper.h"
877d54e9	6	#include "log.h"
a4bff6ef	7	#include "log-context.h"
dccca82b	8	#include "process-util.h"
a0b15b41	9	#include "string-util.h"
7c7a9138	10	#include "strv.h"
965040d8	11	#include "tests.h"
877d54e9	12
f8e6f4aa ZJS	13	#define X10(x) x x x x x x x x x x
	14	#define X100(x) X10(X10(x))
	15	#define X1000(x) X100(X10(x))
877d54e9	16
8161f608 YW	17	static int fail_with_EINVAL(void) {
	18	assert_return(false, -EINVAL);
	19	return 0;
	20	}
	21
	22	static void test_assert_return_is_critical(void) {
	23	SAVE_ASSERT_RETURN_IS_CRITICAL;
	24
	25	log_set_assert_return_is_critical(false);
	26	assert_se(fail_with_EINVAL() == -EINVAL);
	27
	28	log_set_assert_return_is_critical(true);
	29	ASSERT_RETURN_IS_CRITICAL(false, assert_se(fail_with_EINVAL() == -EINVAL));
	30	assert_se(log_get_assert_return_is_critical() == true);
	31	ASSERT_RETURN_EXPECTED(assert_se(fail_with_EINVAL() == -EINVAL));
	32	assert_se(log_get_assert_return_is_critical() == true);
	33	ASSERT_RETURN_EXPECTED_SE(fail_with_EINVAL() == -EINVAL);
	34	assert_se(log_get_assert_return_is_critical() == true);
	35	}
	36
a0b15b41 ZJS	37	static void test_file(void) {
	38	log_info("__FILE__: %s", __FILE__);
	39	log_info("RELATIVE_SOURCE_PATH: %s", RELATIVE_SOURCE_PATH);
	40	log_info("PROJECT_FILE: %s", PROJECT_FILE);
	41
f21b863e	42	assert_se(startswith(__FILE__, RELATIVE_SOURCE_PATH "/"));
a0b15b41 ZJS	43	}
a0b15b41 ZJS	44
52d86690	45	static void test_log_struct(void) {
877d54e9	46	log_struct(LOG_INFO,
52d86690	47	"MESSAGE=Waldo PID="PID_FMT" (no errno)", getpid_cached(),
a1230ff9	48	"SERVICE=piepapo");
877d54e9	49
3cf6a3a3	50	/* The same as above, just using LOG_MESSAGE() and LOG_ITEM(), which is generally recommended */
92663a5e ZJS	51	log_struct(LOG_INFO,
92663a5e ZJS	52	LOG_MESSAGE("Waldo PID="PID_FMT" (no errno)", getpid_cached()),
3cf6a3a3	53	LOG_ITEM("SERVICE=piepapo"));
52d86690	54
92663a5e ZJS	55	log_struct_errno(LOG_INFO, EILSEQ,
92663a5e ZJS	56	LOG_MESSAGE("Waldo PID="PID_FMT": %m (normal)", getpid_cached()),
3cf6a3a3	57	LOG_ITEM("SERVICE=piepapo"));
92663a5e	58
52d86690	59	log_struct_errno(LOG_INFO, SYNTHETIC_ERRNO(EILSEQ),
92663a5e	60	LOG_MESSAGE("Waldo PID="PID_FMT": %m (synthetic)", getpid_cached()),
3cf6a3a3	61	LOG_ITEM("SERVICE=piepapo"));
877d54e9	62
963ddb91	63	log_struct(LOG_INFO,
92663a5e	64	LOG_MESSAGE("Foobar PID="PID_FMT, getpid_cached()),
3cf6a3a3	65	LOG_ITEM("FORMAT_STR_TEST=1=%i A=%c 2=%hi 3=%li 4=%lli 1=%p foo=%s 2.5=%g 3.5=%g 4.5=%Lg",
9ec7d7ae	66	(int) 1, 'A', (short) 2, (long) 3, (long long) 4, (void*) 1, "foo", (float) 2.5f, (double) 3.5, (long double) 4.5),
3cf6a3a3	67	LOG_ITEM("SUFFIX=GOT IT"));
f8e6f4aa ZJS	68	}
	69
	70	static void test_long_lines(void) {
	71	log_object_internal(LOG_NOTICE,
	72	EUCLEAN,
	73	X1000("abcd_") ".txt",
	74	1000000,
	75	X1000("fff") "unc",
	76	"OBJECT=",
	77	X1000("obj_") "ect",
	78	"EXTRA=",
	79	X1000("ext_") "tra",
	80	"asdfasdf %s asdfasdfa", "foobar");
	81	}
	82
59c1546b YW	83	static void test_log_syntax(void) {
	84	assert_se(log_syntax("unit", LOG_ERR, "filename", 10, EINVAL, "EINVAL: %s: %m", "hogehoge") == -EINVAL);
	85	assert_se(log_syntax("unit", LOG_ERR, "filename", 10, -ENOENT, "ENOENT: %s: %m", "hogehoge") == -ENOENT);
	86	assert_se(log_syntax("unit", LOG_ERR, "filename", 10, SYNTHETIC_ERRNO(ENOTTY), "ENOTTY: %s: %m", "hogehoge") == -ENOTTY);
	87	}
	88
7c7a9138 DDM	89	static void test_log_context(void) {
	90	{
	91	char **strv = STRV_MAKE("FIRST=abc", "SECOND=qrs");
	92
	93	LOG_CONTEXT_PUSH("THIRD=pfs");
	94	LOG_CONTEXT_PUSH("FOURTH=def");
	95	LOG_CONTEXT_PUSH_STRV(strv);
	96	LOG_CONTEXT_PUSH_STRV(strv);
	97
88335453 DDM	98	/* Test that the log context was set up correctly. The strv we pushed twice should only
	99	* result in one log context which is reused. */
	100	assert_se(log_context_num_contexts() == 3);
	101	assert_se(log_context_num_fields() == 4);
7c7a9138 DDM	102
	103	/* Test that everything still works with modifications to the log context. */
	104	test_log_struct();
	105	test_long_lines();
	106	test_log_syntax();
	107
	108	{
	109	LOG_CONTEXT_PUSH("FIFTH=123");
	110	LOG_CONTEXT_PUSH_STRV(strv);
	111
	112	/* Check that our nested fields got added correctly. */
88335453 DDM	113	assert_se(log_context_num_contexts() == 4);
88335453 DDM	114	assert_se(log_context_num_fields() == 5);
7c7a9138 DDM	115
	116	/* Test that everything still works in a nested block. */
	117	test_log_struct();
	118	test_long_lines();
	119	test_log_syntax();
	120	}
	121
	122	/* Check that only the fields from the nested block got removed. */
88335453 DDM	123	assert_se(log_context_num_contexts() == 3);
88335453 DDM	124	assert_se(log_context_num_fields() == 4);
7c7a9138 DDM	125	}
	126
	127	assert_se(log_context_num_contexts() == 0);
	128	assert_se(log_context_num_fields() == 0);
	129
	130	{
88335453	131	_cleanup_(log_context_unrefp) LogContext *ctx = NULL;
7c7a9138 DDM	132
7c7a9138 DDM	133	char **strv = STRV_MAKE("SIXTH=ijn", "SEVENTH=PRP");
81b3565e	134	assert_se(ctx = log_context_new_strv(strv, /owned=/ false));
7c7a9138 DDM	135
	136	assert_se(log_context_num_contexts() == 1);
	137	assert_se(log_context_num_fields() == 2);
	138
	139	/* Test that everything still works with a manually configured log context. */
	140	test_log_struct();
	141	test_long_lines();
	142	test_log_syntax();
	143	}
	144
	145	{
	146	char **strv = NULL;
	147
	148	assert_se(strv = strv_new("ABC", "DEF"));
	149	LOG_CONTEXT_CONSUME_STRV(strv);
	150
	151	assert_se(log_context_num_contexts() == 1);
	152	assert_se(log_context_num_fields() == 2);
	153	}
	154
2461943b LB	155	{
	156	/* Test that everything still works with a mixed strv and iov. */
	157	struct iovec iov[] = {
	158	IOVEC_MAKE_STRING("ABC=def"),
	159	IOVEC_MAKE_STRING("GHI=jkl"),
	160	};
	161	_cleanup_free_ struct iovec_wrapper *iovw = iovw_new();
	162	assert_se(iovw);
	163	assert_se(iovw_consume(iovw, strdup("MNO=pqr"), STRLEN("MNO=pqr") + 1) == 0);
	164
88335453	165	LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
2461943b LB	166	LOG_CONTEXT_PUSH_IOV(iov, ELEMENTSOF(iov));
	167	LOG_CONTEXT_CONSUME_IOV(iovw->iovec, iovw->count);
	168	LOG_CONTEXT_PUSH("STU=vwx");
	169
	170	assert_se(log_context_num_contexts() == 3);
	171	assert_se(log_context_num_fields() == 4);
	172
	173	test_log_struct();
	174	test_long_lines();
	175	test_log_syntax();
	176	}
	177
81b3565e DDM	178	{
	179	LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
	180	LOG_CONTEXT_PUSH_KEY_VALUE("ABC=", "QED");
	181	assert_se(log_context_num_contexts() == 1);
	182	assert_se(log_context_num_fields() == 1);
	183
	184	test_log_struct();
	185	test_long_lines();
	186	test_log_syntax();
	187	}
	188
7c7a9138 DDM	189	assert_se(log_context_num_contexts() == 0);
	190	assert_se(log_context_num_fields() == 0);
	191	}
	192
ee2975a9 DDM	193	static void test_log_prefix(void) {
	194	{
	195	LOG_SET_PREFIX("ABC");
	196
	197	test_log_struct();
	198	test_long_lines();
	199	test_log_syntax();
	200
	201	{
	202	LOG_SET_PREFIX("QED");
	203
	204	test_log_struct();
	205	test_long_lines();
	206	test_log_syntax();
	207	}
	208
	209	test_log_struct();
	210	test_long_lines();
	211	test_log_syntax();
	212	}
	213
	214	test_log_struct();
	215	test_long_lines();
	216	test_log_syntax();
	217	}
	218
f8e6f4aa	219	int main(int argc, char* argv[]) {
965040d8 YW	220	test_setup_logging(LOG_DEBUG);
965040d8 YW	221
268f5807 MY	222	ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(EINVAL)));
	223	ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(-EINVAL)));
	224	assert_cc(!IS_SYNTHETIC_ERRNO(EINVAL));
	225	assert_cc(!IS_SYNTHETIC_ERRNO(-EINVAL));
	226	ASSERT_TRUE(IS_SYNTHETIC_ERRNO(SYNTHETIC_ERRNO(0)));
	227	assert_cc(!IS_SYNTHETIC_ERRNO(0));
	228	ASSERT_EQ(ERRNO_VALUE(EINVAL), EINVAL);
	229	ASSERT_EQ(ERRNO_VALUE(SYNTHETIC_ERRNO(-EINVAL)), EINVAL);
	230
8161f608	231	test_assert_return_is_critical();
a0b15b41 ZJS	232	test_file();
a0b15b41 ZJS	233
169d980b ZJS	234	assert_se(log_info_errno(SYNTHETIC_ERRNO(EUCLEAN), "foo") == -EUCLEAN);
	235
	236	for (int target = 0; target < _LOG_TARGET_MAX; target++) {
f8e6f4aa ZJS	237	log_set_target(target);
	238	log_open();
	239
52d86690	240	test_log_struct();
f8e6f4aa	241	test_long_lines();
59c1546b	242	test_log_syntax();
7c7a9138	243	test_log_context();
ee2975a9	244	test_log_prefix();
f8e6f4aa	245	}
963ddb91	246
877d54e9 LP	247	return 0;
877d54e9 LP	248	}