selftests/proc: add verbose more for tests to facilitate debugging

Add verbose mode to the proc tests to print debugging information.
Usage: proc-pid-vm -v

Signed-off-by: Suren Baghdasaryan <surenb@google.com>

diff --git a/tools/testing/selftests/proc/proc-maps-race.c b/tools/testing/selftests/proc/proc-maps-race.c
index 6acdafdac9db66894941ed9402d9051c88a438a4..5f912fedd6cff610fa367100b945d699b72f9325 100644 (file)
--- a/tools/testing/selftests/proc/proc-maps-race.c
+++ b/tools/testing/selftests/proc/proc-maps-race.c
@@ -39,6 +39,7 @@
 
 static unsigned long test_duration_sec = 5UL;
 static int page_size;
+static bool verbose;
 
 /* /proc/pid/maps parsing routines */
 struct page_content {
@@ -207,6 +208,99 @@ static void stop_vma_modifier(struct vma_modifier_info *mod_info)
        signal_state(mod_info, SETUP_MODIFY_MAPS);
 }
 
+static void print_first_lines(char *text, int nr)
+{
+       const char *end = text;
+
+       while (nr && (end = strchr(end, '\n')) != NULL) {
+               nr--;
+               end++;
+       }
+
+       if (end) {
+               int offs = end - text;
+
+               text[offs] = '\0';
+               printf(text);
+               text[offs] = '\n';
+               printf("\n");
+       } else {
+               printf(text);
+       }
+}
+
+static void print_last_lines(char *text, int nr)
+{
+       const char *start = text + strlen(text);
+
+       nr++; /* to ignore the last newline */
+       while (nr) {
+               while (start > text && *start != '\n')
+                       start--;
+               nr--;
+               start--;
+       }
+       printf(start);
+}
+
+static void print_boundaries(const char *title,
+                            struct page_content *page1,
+                            struct page_content *page2)
+{
+       if (!verbose)
+               return;
+
+       printf("%s", title);
+       /* Print 3 boundary lines from each page */
+       print_last_lines(page1->data, 3);
+       printf("-----------------page boundary-----------------\n");
+       print_first_lines(page2->data, 3);
+}
+
+static bool print_boundaries_on(bool condition, const char *title,
+                               struct page_content *page1,
+                               struct page_content *page2)
+{
+       if (verbose && condition)
+               print_boundaries(title, page1, page2);
+
+       return condition;
+}
+
+static void report_test_start(const char *name)
+{
+       if (verbose)
+               printf("==== %s ====\n", name);
+}
+
+static struct timespec print_ts;
+
+static void start_test_loop(struct timespec *ts)
+{
+       if (verbose)
+               print_ts.tv_sec = ts->tv_sec;
+}
+
+static void end_test_iteration(struct timespec *ts)
+{
+       if (!verbose)
+               return;
+
+       /* Update every second */
+       if (print_ts.tv_sec == ts->tv_sec)
+               return;
+
+       printf(".");
+       fflush(stdout);
+       print_ts.tv_sec = ts->tv_sec;
+}
+
+static void end_test_loop(void)
+{
+       if (verbose)
+               printf("\n");
+}
+
 static void capture_mod_pattern(int maps_fd,
                                struct vma_modifier_info *mod_info,
                                struct page_content *page1,
@@ -218,18 +312,24 @@ static void capture_mod_pattern(int maps_fd,
                                struct line_content *restored_last_line,
                                struct line_content *restored_first_line)
 {
+       print_boundaries("Before modification", page1, page2);
+
        signal_state(mod_info, SETUP_MODIFY_MAPS);
        wait_for_state(mod_info, SETUP_MAPS_MODIFIED);
 
        /* Copy last line of the first page and first line of the last page */
        read_boundary_lines(maps_fd, page1, page2, mod_last_line, mod_first_line);
 
+       print_boundaries("After modification", page1, page2);
+
        signal_state(mod_info, SETUP_RESTORE_MAPS);
        wait_for_state(mod_info, SETUP_MAPS_RESTORED);
 
        /* Copy last line of the first page and first line of the last page */
        read_boundary_lines(maps_fd, page1, page2, restored_last_line, restored_first_line);
 
+       print_boundaries("After restore", page1, page2);
+
        mod_info->vma_mod_check(mod_last_line, mod_first_line,
                                restored_last_line, restored_first_line);
 
@@ -301,6 +401,7 @@ static void test_maps_tearing_from_split(int maps_fd,
        mod_info->vma_restore = merge_vma;
        mod_info->vma_mod_check = check_split_result;
 
+       report_test_start("Tearing from split");
        capture_mod_pattern(maps_fd, mod_info, page1, page2, last_line, first_line,
                            &split_last_line, &split_first_line,
                            &restored_last_line, &restored_first_line);
@@ -313,6 +414,7 @@ static void test_maps_tearing_from_split(int maps_fd,
        struct timespec start_ts, end_ts;
 
        clock_gettime(CLOCK_MONOTONIC_COARSE, &start_ts);
+       start_test_loop(&start_ts);
        do {
                bool last_line_changed;
                bool first_line_changed;
@@ -332,12 +434,18 @@ static void test_maps_tearing_from_split(int maps_fd,
                         * In that case new first line will be the same as the
                         * last restored line.
                         */
-                       assert(!strcmp(new_first_line.text, split_first_line.text) ||
-                              !strcmp(new_first_line.text, restored_last_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, split_first_line.text) &&
+                                       strcmp(new_first_line.text, restored_last_line.text),
+                                       "Split result invalid", page1, page2));
                } else {
                        /* The vmas should be consistent with merge results */
-                       assert(!strcmp(new_last_line.text, restored_last_line.text) &&
-                              !strcmp(new_first_line.text, restored_first_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_last_line.text, restored_last_line.text),
+                                       "Merge result invalid", page1, page2));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, restored_first_line.text),
+                                       "Merge result invalid", page1, page2));
                }
                /*
                 * First and last lines should change in unison. If the last
@@ -362,7 +470,9 @@ static void test_maps_tearing_from_split(int maps_fd,
                        vma_end == split_first_line.end_addr));
 
                clock_gettime(CLOCK_MONOTONIC_COARSE, &end_ts);
+               end_test_iteration(&end_ts);
        } while (end_ts.tv_sec - start_ts.tv_sec < test_duration_sec);
+       end_test_loop();
 
        /* Signal the modifyer thread to stop and wait until it exits */
        signal_state(mod_info, TEST_DONE);
@@ -409,6 +519,7 @@ static void test_maps_tearing_from_resize(int maps_fd,
        mod_info->vma_restore = expand_vma;
        mod_info->vma_mod_check = check_shrink_result;
 
+       report_test_start("Tearing from resize");
        capture_mod_pattern(maps_fd, mod_info, page1, page2, last_line, first_line,
                            &shrunk_last_line, &shrunk_first_line,
                            &restored_last_line, &restored_first_line);
@@ -421,6 +532,7 @@ static void test_maps_tearing_from_resize(int maps_fd,
        struct timespec start_ts, end_ts;
 
        clock_gettime(CLOCK_MONOTONIC_COARSE, &start_ts);
+       start_test_loop(&start_ts);
        do {
                unsigned long vma_start;
                unsigned long vma_end;
@@ -437,12 +549,18 @@ static void test_maps_tearing_from_resize(int maps_fd,
                         * again. In that case new first line will be the same
                         * as the last restored line.
                         */
-                       assert(!strcmp(new_first_line.text, shrunk_first_line.text) ||
-                              !strcmp(new_first_line.text, restored_last_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, shrunk_first_line.text) &&
+                                       strcmp(new_first_line.text, restored_last_line.text),
+                                       "Shrink result invalid", page1, page2));
                } else {
                        /* The vmas should be consistent with the original/resored state */
-                       assert(!strcmp(new_last_line.text, restored_last_line.text) &&
-                              !strcmp(new_first_line.text, restored_first_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_last_line.text, restored_last_line.text),
+                                       "Expand result invalid", page1, page2));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, restored_first_line.text),
+                                       "Expand result invalid", page1, page2));
                }
 
                /* Check if PROCMAP_QUERY ioclt() finds the right VMA */
@@ -456,7 +574,9 @@ static void test_maps_tearing_from_resize(int maps_fd,
                        vma_end - vma_start == page_size));
 
                clock_gettime(CLOCK_MONOTONIC_COARSE, &end_ts);
+               end_test_iteration(&end_ts);
        } while (end_ts.tv_sec - start_ts.tv_sec < test_duration_sec);
+       end_test_loop();
 
        /* Signal the modifyer thread to stop and wait until it exits */
        signal_state(mod_info, TEST_DONE);
@@ -512,6 +632,7 @@ static void test_maps_tearing_from_remap(int maps_fd,
        mod_info->vma_restore = patch_vma;
        mod_info->vma_mod_check = check_remap_result;
 
+       report_test_start("Tearing from remap");
        capture_mod_pattern(maps_fd, mod_info, page1, page2, last_line, first_line,
                            &remapped_last_line, &remapped_first_line,
                            &restored_last_line, &restored_first_line);
@@ -524,6 +645,7 @@ static void test_maps_tearing_from_remap(int maps_fd,
        struct timespec start_ts, end_ts;
 
        clock_gettime(CLOCK_MONOTONIC_COARSE, &start_ts);
+       start_test_loop(&start_ts);
        do {
                unsigned long vma_start;
                unsigned long vma_end;
@@ -540,12 +662,18 @@ static void test_maps_tearing_from_remap(int maps_fd,
                         * again. In that case new first line will be the same
                         * as the last restored line.
                         */
-                       assert(!strcmp(new_first_line.text, remapped_first_line.text) ||
-                              !strcmp(new_first_line.text, restored_last_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, remapped_first_line.text) &&
+                                       strcmp(new_first_line.text, restored_last_line.text),
+                                       "Remap result invalid", page1, page2));
                } else {
                        /* The vmas should be consistent with the original/resored state */
-                       assert(!strcmp(new_last_line.text, restored_last_line.text) &&
-                              !strcmp(new_first_line.text, restored_first_line.text));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_last_line.text, restored_last_line.text),
+                                       "Remap restore result invalid", page1, page2));
+                       assert(!print_boundaries_on(
+                                       strcmp(new_first_line.text, restored_first_line.text),
+                                       "Remap restore result invalid", page1, page2));
                }
 
                /* Check if PROCMAP_QUERY ioclt() finds the right VMA */
@@ -561,7 +689,9 @@ static void test_maps_tearing_from_remap(int maps_fd,
                        vma_end - vma_start == page_size));
 
                clock_gettime(CLOCK_MONOTONIC_COARSE, &end_ts);
+               end_test_iteration(&end_ts);
        } while (end_ts.tv_sec - start_ts.tv_sec < test_duration_sec);
+       end_test_loop();
 
        /* Signal the modifyer thread to stop and wait until it exits */
        signal_state(mod_info, TEST_DONE);
@@ -571,6 +701,7 @@ int usage(void)
 {
        fprintf(stderr, "Userland /proc/pid/{s}maps race test cases\n");
        fprintf(stderr, "  -d: Duration for time-consuming tests\n");
+       fprintf(stderr, "  -v: Verbose mode\n");
        fprintf(stderr, "  -h: Help screen\n");
        exit(-1);
 }
@@ -588,9 +719,11 @@ int main(int argc, char **argv)
        pid_t pid;
        int opt;
 
-       while ((opt = getopt(argc, argv, "d:h")) != -1) {
+       while ((opt = getopt(argc, argv, "d:vh")) != -1) {
                if (opt == 'd')
                        test_duration_sec = strtoul(optarg, NULL, 0);
+               else if (opt == 'v')
+                       verbose = true;
                else if (opt == 'h')
                        usage();
        }