/* ipc_logging/ipc_logging_test.c * * Copyright (c) 2013-2015, The Linux Foundation. All rights reserved. * * This program is free software; you can redistribute it and/or modify * it under the terms of the GNU General Public License version 2 and * only version 2 as published by the Free Software Foundation. * * This program is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the * GNU General Public License for more details. */ #include #include #include #include #include #include #include #include "../../../kernel/trace/ipc_logging_private.h" /** * Unit test assertion for logging test cases. * * @a lval * @b rval * @cmp comparison operator * * Assertion fails if (@a cmp @b) is not true which then * logs the function and line number where the error occurred * along with the values of @a and @b. * * Assumes that the following local variables exist: * @s - sequential output file pointer * @failed - set to true if test fails */ #define UT_ASSERT_INT(a, cmp, b) \ { \ int a_tmp = (a); \ int b_tmp = (b); \ if (!((a_tmp)cmp(b_tmp))) { \ seq_printf(s, \ "%s:%d Fail: " #a "(%d) " #cmp " " #b "(%d)\n", \ __func__, __LINE__, \ a_tmp, b_tmp); \ failed = 1; \ break; \ } \ } #define UT_ASSERT_PTR(a, cmp, b) \ { \ void *a_tmp = (a); \ void *b_tmp = (b); \ if (!((a_tmp)cmp(b_tmp))) { \ seq_printf(s, \ "%s:%d Fail: " #a "(%p) " #cmp " " #b "(%p)\n", \ __func__, __LINE__, \ a_tmp, b_tmp); \ failed = 1; \ break; \ } \ } #define UT_ASSERT_UINT(a, cmp, b) \ { \ unsigned a_tmp = (a); \ unsigned b_tmp = (b); \ if (!((a_tmp)cmp(b_tmp))) { \ seq_printf(s, \ "%s:%d Fail: " #a "(%u) " #cmp " " #b "(%u)\n", \ __func__, __LINE__, \ a_tmp, b_tmp); \ failed = 1; \ break; \ } \ } #define UT_ASSERT_HEX(a, cmp, b) \ { \ unsigned a_tmp = (a); \ unsigned b_tmp = (b); \ if (!((a_tmp)cmp(b_tmp))) { \ seq_printf(s, \ "%s:%d Fail: " #a "(%x) " #cmp " " #b "(%x)\n", \ __func__, __LINE__, \ a_tmp, b_tmp); \ failed = 1; \ break; \ } \ } /** * In-range unit test assertion for test cases. * * @a lval * @minv Minimum value * @maxv Maximum value * * Assertion fails if @a is not on the exclusive range minv, maxv * ((@a < @minv) or (@a > @maxv)). In the failure case, the macro * logs the function and line number where the error occurred along * with the values of @a and @minv, @maxv. * * Assumes that the following local variables exist: * @s - sequential output file pointer * @failed - set to true if test fails */ #define UT_ASSERT_INT_IN_RANGE(a, minv, maxv) \ { \ int a_tmp = (a); \ int minv_tmp = (minv); \ int maxv_tmp = (maxv); \ if (((a_tmp) < (minv_tmp)) || ((a_tmp) > (maxv_tmp))) { \ seq_printf(s, \ "%s:%d Fail: " #a "(%d) < " #minv "(%d) or " \ #a "(%d) > " #maxv "(%d)\n", \ __func__, __LINE__, \ a_tmp, minv_tmp, a_tmp, maxv_tmp); \ failed = 1; \ break; \ } \ } #define MAX_MSG_DECODED_SIZE (MAX_MSG_SIZE*4) #define TIME_SEC_OFFSET 1 #define TIME_SEC_FIELD_SIZE 7 #define TIME_NSEC_OFFSET 8 #define TIME_NSEC_FIELD_SIZE 10 /* * Extracted IPC logs have the form * * [dddddd.ddddddddd/xxxxxxxxxxxxxxxxxx]_An example log string * * where "d" represents a decimal digit (for the kernel timestamp), 'x' * represents a hex digit (for the QTimer timestamp), '.', '[', ']', * and '/' represent themselves, and '_' represents a space. * "An example log string" represents the log message itself. * - There are 15 'd' characters * - There are 18 'x' characters * - There are 5 special characters ('[', ']', '.', '_', '/') * This adds up to 38, which is the index at which the 'A' in * "An example log string" starts. */ #define STRING_OFFSET 38 /** * String compare unit test assertion for test cases. * * @str1 One string * @str2 Another string * @count: The maximum number of bytes to compare * * Assertion fails if @count bytes of @str1 is not equal to @str2. * In the failure case, the macro logs the funtion and line number * where the error occurred along with the values of @str1, @str2 * and @count. * * Assumes that the following local variables exist: * @s - sequential output file pointer * @failed - set to true if test fails */ #define UT_ASSERT_STRING_COMPARE(str1, str2) \ { \ if (strcmp(str1, str2)) { \ seq_printf(s, "%s:%d Fail:String compare[%s][%s]\n", \ __func__, __LINE__, str1, str2); \ failed = 1; \ break; \ } \ } /** * String to unsigned long unit test assertion for test cases. * * @str Input string * @base Integer base * @val Output unsigned long * * Assertion fails if @str is not able to convert into unsigned long. * In the failure case, the macro logs the function and line number * where the error occurred along with the value of @str. * * Assumes that the following local variables exist: * @s - sequential output file pointer * @failed - set to true if test fails */ #define UT_ASSERT_STRING_TO_UL(str, base, val) \ { \ if (kstrtoul(str, base, &val)) { \ seq_printf(s, \ "%s:%d Fail: Time converstion str[%s]\n", \ __func__, __LINE__, str); \ failed = 1; \ break; \ } \ } #define DECODE_TIME(in_buff, val) \ do { \ char sec[10] = {"\0"}; \ char nsec[10] = {"\0"}; \ char *substr = NULL; \ unsigned long t_sec = 0; \ unsigned long t_nsec = 0; \ scnprintf(sec, TIME_SEC_FIELD_SIZE, in_buff + TIME_SEC_OFFSET); \ substr = strrchr(sec, ' '); \ if (substr) \ substr++; \ else \ substr = sec; \ UT_ASSERT_STRING_TO_UL(substr, 10, t_sec);\ scnprintf(nsec, TIME_NSEC_FIELD_SIZE, in_buff + TIME_NSEC_OFFSET); \ UT_ASSERT_STRING_TO_UL(nsec, 10, t_nsec);\ do_div(t_nsec, 1000000U); \ val = (t_sec * 1000) + t_nsec; \ } while (0) /** * ipc_logging_ut_basic - Basic sanity test using local loopback. * * @s: pointer to output file * * This test simulates create, read, write and destroy of ipc_logging_context * when no other drivers implemented IPC_LOGGING. */ static void ipc_logging_ut_basic(struct seq_file *s) { static void *ipc_log_test_ctxt; int ipc_log_test_pages = 2; int failed = 0; char *test_data = {"hello world\n"}; char *read_data = kzalloc(MAX_MSG_DECODED_SIZE, GFP_KERNEL); char log1[30] = {"\0"}; unsigned long mtime1 = 0; char log2[30] = {"\0"}; unsigned long mtime2 = 0; int read_size; seq_printf(s, "Running %s\n", __func__); do { ipc_log_test_ctxt = ipc_log_context_create(ipc_log_test_pages, "ipc_logging_test", 0); UT_ASSERT_PTR(ipc_log_test_ctxt, !=, NULL); ipc_log_string(ipc_log_test_ctxt, "%s", test_data); read_size = ipc_log_extract(ipc_log_test_ctxt, read_data, MAX_MSG_DECODED_SIZE); scnprintf(log1, sizeof(log1), read_data + STRING_OFFSET); DECODE_TIME(read_data, mtime1); UT_ASSERT_STRING_COMPARE(log1, test_data); msleep(50); ipc_log_string(ipc_log_test_ctxt, "%s", test_data); read_size = ipc_log_extract(ipc_log_test_ctxt, read_data, MAX_MSG_DECODED_SIZE); scnprintf(log2, sizeof(log2), read_data + STRING_OFFSET); DECODE_TIME(read_data, mtime2); UT_ASSERT_STRING_COMPARE(log2, test_data); UT_ASSERT_INT_IN_RANGE((mtime2 - mtime1), 50, 65); seq_printf(s, "\tOK\n"); } while (0); if (failed) { pr_err("%s: Failed\n", __func__); seq_printf(s, "\tFailed\n"); } ipc_log_context_destroy(ipc_log_test_ctxt); } /** * ipc_logging_ut_wrap_test - Verify log wrapping. * * @s: pointer to output file * * This tests fills a log multiple times to verify that expected combinations * of wrapping are handled correctly. Specifically, this test case confirms: * * splitting messages across page boundaries works as expected * * all combinations of read/write indexes are working as expected */ static void ipc_logging_ut_wrap_test(struct seq_file *s) { static void *ctx; int failed = 0; char *test_data = {"hello world\n"}; char *read_data = kzalloc(MAX_MSG_DECODED_SIZE, GFP_KERNEL); char log1[30] = {"\0"}; unsigned long mtime1 = 0; char log2[30] = {"\0"}; unsigned long mtime2 = 0; int read_size; seq_printf(s, "Running %s\n", __func__); do { ctx = ipc_log_context_create(3, "ipc_logging_test", 0); UT_ASSERT_PTR(ctx, !=, NULL); ipc_log_string(ctx, "%s", test_data); read_size = ipc_log_extract(ctx, read_data, MAX_MSG_DECODED_SIZE); scnprintf(log1, sizeof(log1), read_data + STRING_OFFSET); DECODE_TIME(read_data, mtime1); UT_ASSERT_STRING_COMPARE(log1, test_data); msleep(50); ipc_log_string(ctx, "%s", test_data); read_size = ipc_log_extract(ctx, read_data, MAX_MSG_DECODED_SIZE); scnprintf(log2, sizeof(log2), read_data + STRING_OFFSET); DECODE_TIME(read_data, mtime2); UT_ASSERT_STRING_COMPARE(log2, test_data); UT_ASSERT_INT_IN_RANGE((mtime2 - mtime1), 50, 65); seq_printf(s, "\tOK\n"); } while (0); if (failed) { pr_err("%s: Failed\n", __func__); seq_printf(s, "\tFailed\n"); } ipc_log_context_destroy(ctx); } /** * extraction_dump - Dump unit test logs used to verify log extraction tool. * * @s: pointer to output file * * Generates several different logs that are used as part of the log extraction * tool unit test. Multipage tests with full pages will wrap around, so * the logs they create shouldn't start with "line 0". Tests that create * partially full pages will not wrap around, so the logs they create * should start with "line 0". * * Note: This tool will crash the kernel to trigger the memory dump. */ static void extraction_dump(struct seq_file *s) { int failed = 0; int n; void *ctx; char data[MAX_MSG_DECODED_SIZE]; /* * msgs_per_page - The number of TSV messages that can fit in one * log page. 180 is an approximation used for this test case. */ const int msgs_per_page = 180; seq_printf(s, "Running %s\n", __func__); do { /* Create 1-page partially-full log */ ctx = ipc_log_context_create(1, "ut_partial_1", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < msgs_per_page / 2; ++n) ipc_log_string(ctx, "line %d\n", n); /* Create 1-page full log */ ctx = ipc_log_context_create(1, "ut_full_1", 0); UT_ASSERT_PTR(ctx, !=, NULL); /* Add 20 to msgs_per_page to ensure the log wraps */ for (n = 0; n < msgs_per_page + 20; ++n) ipc_log_string(ctx, "line %d\n", n); /* Create multi-page partially-full log */ ctx = ipc_log_context_create(3, "ut_partial_3", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < (3 * msgs_per_page) / 2; ++n) ipc_log_string(ctx, "line %d\n", n); /* Create multi-page full log */ ctx = ipc_log_context_create(3, "ut_full_3", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < 3 * msgs_per_page; ++n) ipc_log_string(ctx, "line %d\n", n); /* Create multi-page full log and empty it */ ctx = ipc_log_context_create(2, "ut_read_extract_2", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < 2 * msgs_per_page; ++n) ipc_log_string(ctx, "line %d\n", n); do { n = ipc_log_extract(ctx, data, sizeof(data)); UT_ASSERT_INT(n, >=, 0) } while (n > 0); /* * Create multi-page full log that wraps to the last page. */ ctx = ipc_log_context_create(3, "ut_full_3_overwrite", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < 8 * msgs_per_page; ++n) ipc_log_string(ctx, "line %d\n", n); /* * Create multi-page full log that wraps to the last page, * and then empty it */ ctx = ipc_log_context_create(3, "ut_full_3_ow_extrct", 0); UT_ASSERT_PTR(ctx, !=, NULL); for (n = 0; n < 8 * msgs_per_page; ++n) ipc_log_string(ctx, "pre-extract %d\n", n); do { n = ipc_log_extract(ctx, data, sizeof(data)); UT_ASSERT_INT(n, >=, 0) } while (n > 0); for (n = 0; n < 2 * msgs_per_page; ++n) ipc_log_string(ctx, "post-extract %d\n", n); if (failed) break; /* Crash system to start memory dump */ panic("Crashing system to collect memory dump\n"); } while (0); if (failed) { pr_err("%s: Failed\n", __func__); seq_printf(s, "\tFailed\n"); } } /** * ipc_logging_ut_nd_read - Test non-destructive read support. * * @s: pointer to output file * * This test verifies non-destructive read support used by debugfs. */ static void ipc_logging_ut_nd_read(struct seq_file *s) { const int msgs_per_page = 180; const int num_pages = 3; int failed = 0; int n; int i; int read_size; char *data; char expected[128]; void *ctx = NULL; seq_printf(s, "Running %s\n", __func__); data = kzalloc(MAX_MSG_DECODED_SIZE, GFP_KERNEL); do { UT_ASSERT_PTR(data, !=, NULL); ctx = ipc_log_context_create(num_pages, "ipc_logging_ut_nd_read", 0); UT_ASSERT_PTR(ctx, !=, NULL); /* Fill log and do non-destructive read of all lines */ for (n = 0; n < msgs_per_page * num_pages; ++n) ipc_log_string(ctx, "line %d", n); do { read_size = ipc_log_extract(ctx, data, MAX_MSG_DECODED_SIZE); } while (read_size > 0); /* Write a single line and verify only single line read */ for (n = 1000; n < 1000 + msgs_per_page * num_pages; ++n) { scnprintf(expected, sizeof(expected), "line %d\n", n); ipc_log_string(ctx, "%s", expected); i = ipc_log_extract(ctx, data, MAX_MSG_DECODED_SIZE); UT_ASSERT_INT(0, <, i); UT_ASSERT_INT(STRING_OFFSET, <, strlen(data)); UT_ASSERT_STRING_COMPARE(expected, data + STRING_OFFSET); i = ipc_log_extract(ctx, data, MAX_MSG_DECODED_SIZE); UT_ASSERT_INT(0, ==, i); } seq_puts(s, "\tOK\n"); } while (0); kfree(data); if (failed) { pr_err("%s: Failed\n", __func__); seq_puts(s, "\tFailed\n"); } ipc_log_context_destroy(ctx); } static struct dentry *dent; static int debugfs_show(struct seq_file *s, void *data) { void (*show)(struct seq_file *) = s->private; show(s); return 0; } static int debug_open(struct inode *inode, struct file *file) { return single_open(file, debugfs_show, inode->i_private); } static const struct file_operations debug_ops = { .open = debug_open, .release = single_release, .read = seq_read, .llseek = seq_lseek, }; void ipc_logging_debug_create(const char *name, void (*show)(struct seq_file *)) { struct dentry *file; file = debugfs_create_file(name, 0444, dent, show, &debug_ops); if (!file) pr_err("%s: unable to create file '%s'\n", __func__, name); } static int __init ipc_logging_debugfs_init(void) { dent = debugfs_create_dir("ipc_logging_test", 0); if (IS_ERR(dent)) return PTR_ERR(dent); /* * Add Unit Test entries. * * The idea with unit tests is that you can run all of them * from ADB shell by doing: * adb shell * cat ut* * * And if particular tests fail, you can then repeatedly run the * failing tests as you debug and resolve the failing test. */ ipc_logging_debug_create("ut_basic", ipc_logging_ut_basic); ipc_logging_debug_create("ut_wrap_test", ipc_logging_ut_wrap_test); ipc_logging_debug_create("extraction_dump", extraction_dump); ipc_logging_debug_create("ut_nd_read", ipc_logging_ut_nd_read); return 0; } static void ipc_logging_debugfs_exit(void) { if (dent != NULL) debugfs_remove_recursive(dent); } module_init(ipc_logging_debugfs_init); module_exit(ipc_logging_debugfs_exit); MODULE_DESCRIPTION("IPC Logging Unit Test"); MODULE_LICENSE("GPL v2");