Re: Locking API testsuite output mangled

From: Michael Ellerman
Date: Wed Nov 23 2016 - 00:28:07 EST


Christian Kujau <lists@xxxxxxxxxxxxxxx> writes:

> The "Locking API testsuite" output during bootup (with
> CONFIG_DEBUG_LOCKING_API_SELFTESTS=y) on this PowerPC system looks
> mangled, possibly related to the recent printk changes (4bcc595ccd80,
> "printk: reinstate KERN_CONT for printing continuation lines"). Before
> (e.g. with v4.6) it looked like this:
>
> http://nerdbynature.de/bits/4.6.0-rc7/dmesg.txt
>
> See below for the current output.

That's nothing powerpc specific AFAICS, does this fix it?

cheers

diff --git a/lib/locking-selftest.c b/lib/locking-selftest.c
index 872a15a2a637..f3a217ea0388 100644
--- a/lib/locking-selftest.c
+++ b/lib/locking-selftest.c
@@ -980,23 +980,23 @@ static void dotest(void (*testcase_fn)(void), int expected, int lockclass_mask)
#ifndef CONFIG_PROVE_LOCKING
if (expected == FAILURE && debug_locks) {
expected_testcase_failures++;
- printk("failed|");
+ pr_cont("failed|");
}
else
#endif
if (debug_locks != expected) {
unexpected_testcase_failures++;
- printk("FAILED|");
+ pr_cont("FAILED|");

dump_stack();
} else {
testcase_successes++;
- printk(" ok |");
+ pr_cont(" ok |");
}
testcase_total++;

if (debug_locks_verbose)
- printk(" lockclass mask: %x, debug_locks: %d, expected: %d\n",
+ pr_cont(" lockclass mask: %x, debug_locks: %d, expected: %d\n",
lockclass_mask, debug_locks, expected);
/*
* Some tests (e.g. double-unlock) might corrupt the preemption
@@ -1021,26 +1021,26 @@ static inline void print_testname(const char *testname)
#define DO_TESTCASE_1(desc, name, nr) \
print_testname(desc"/"#nr); \
dotest(name##_##nr, SUCCESS, LOCKTYPE_RWLOCK); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_1B(desc, name, nr) \
print_testname(desc"/"#nr); \
dotest(name##_##nr, FAILURE, LOCKTYPE_RWLOCK); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_3(desc, name, nr) \
print_testname(desc"/"#nr); \
dotest(name##_spin_##nr, FAILURE, LOCKTYPE_SPIN); \
dotest(name##_wlock_##nr, FAILURE, LOCKTYPE_RWLOCK); \
dotest(name##_rlock_##nr, SUCCESS, LOCKTYPE_RWLOCK); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_3RW(desc, name, nr) \
print_testname(desc"/"#nr); \
dotest(name##_spin_##nr, FAILURE, LOCKTYPE_SPIN|LOCKTYPE_RWLOCK);\
dotest(name##_wlock_##nr, FAILURE, LOCKTYPE_RWLOCK); \
dotest(name##_rlock_##nr, SUCCESS, LOCKTYPE_RWLOCK); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_6(desc, name) \
print_testname(desc); \
@@ -1050,7 +1050,7 @@ static inline void print_testname(const char *testname)
dotest(name##_mutex, FAILURE, LOCKTYPE_MUTEX); \
dotest(name##_wsem, FAILURE, LOCKTYPE_RWSEM); \
dotest(name##_rsem, FAILURE, LOCKTYPE_RWSEM); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_6_SUCCESS(desc, name) \
print_testname(desc); \
@@ -1060,7 +1060,7 @@ static inline void print_testname(const char *testname)
dotest(name##_mutex, SUCCESS, LOCKTYPE_MUTEX); \
dotest(name##_wsem, SUCCESS, LOCKTYPE_RWSEM); \
dotest(name##_rsem, SUCCESS, LOCKTYPE_RWSEM); \
- printk("\n");
+ pr_cont("\n");

/*
* 'read' variant: rlocks must not trigger.
@@ -1073,7 +1073,7 @@ static inline void print_testname(const char *testname)
dotest(name##_mutex, FAILURE, LOCKTYPE_MUTEX); \
dotest(name##_wsem, FAILURE, LOCKTYPE_RWSEM); \
dotest(name##_rsem, FAILURE, LOCKTYPE_RWSEM); \
- printk("\n");
+ pr_cont("\n");

#define DO_TESTCASE_2I(desc, name, nr) \
DO_TESTCASE_1("hard-"desc, name##_hard, nr); \
@@ -1726,25 +1726,25 @@ static void ww_tests(void)
dotest(ww_test_fail_acquire, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_normal, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_unneeded_slow, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("ww contexts mixing");
dotest(ww_test_two_contexts, FAILURE, LOCKTYPE_WW);
dotest(ww_test_diff_class, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("finishing ww context");
dotest(ww_test_context_done_twice, FAILURE, LOCKTYPE_WW);
dotest(ww_test_context_unlock_twice, FAILURE, LOCKTYPE_WW);
dotest(ww_test_context_fini_early, FAILURE, LOCKTYPE_WW);
dotest(ww_test_context_lock_after_done, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("locking mismatches");
dotest(ww_test_object_unlock_twice, FAILURE, LOCKTYPE_WW);
dotest(ww_test_object_lock_unbalanced, FAILURE, LOCKTYPE_WW);
dotest(ww_test_object_lock_stale_context, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("EDEADLK handling");
dotest(ww_test_edeadlk_normal, SUCCESS, LOCKTYPE_WW);
@@ -1757,11 +1757,11 @@ static void ww_tests(void)
dotest(ww_test_edeadlk_acquire_more_edeadlk_slow, FAILURE, LOCKTYPE_WW);
dotest(ww_test_edeadlk_acquire_wrong, FAILURE, LOCKTYPE_WW);
dotest(ww_test_edeadlk_acquire_wrong_slow, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("spinlock nest unlocked");
dotest(ww_test_spin_nest_unlocked, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

printk(" -----------------------------------------------------\n");
printk(" |block | try |context|\n");
@@ -1771,25 +1771,25 @@ static void ww_tests(void)
dotest(ww_test_context_block, FAILURE, LOCKTYPE_WW);
dotest(ww_test_context_try, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_context_context, SUCCESS, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("try");
dotest(ww_test_try_block, FAILURE, LOCKTYPE_WW);
dotest(ww_test_try_try, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_try_context, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("block");
dotest(ww_test_block_block, FAILURE, LOCKTYPE_WW);
dotest(ww_test_block_try, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_block_context, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");

print_testname("spinlock");
dotest(ww_test_spin_block, FAILURE, LOCKTYPE_WW);
dotest(ww_test_spin_try, SUCCESS, LOCKTYPE_WW);
dotest(ww_test_spin_context, FAILURE, LOCKTYPE_WW);
- printk("\n");
+ pr_cont("\n");
}

void locking_selftest(void)
@@ -1829,32 +1829,32 @@ void locking_selftest(void)

printk(" --------------------------------------------------------------------------\n");
print_testname("recursive read-lock");
- printk(" |");
+ pr_cont(" |");
dotest(rlock_AA1, SUCCESS, LOCKTYPE_RWLOCK);
- printk(" |");
+ pr_cont(" |");
dotest(rsem_AA1, FAILURE, LOCKTYPE_RWSEM);
- printk("\n");
+ pr_cont("\n");

print_testname("recursive read-lock #2");
- printk(" |");
+ pr_cont(" |");
dotest(rlock_AA1B, SUCCESS, LOCKTYPE_RWLOCK);
- printk(" |");
+ pr_cont(" |");
dotest(rsem_AA1B, FAILURE, LOCKTYPE_RWSEM);
- printk("\n");
+ pr_cont("\n");

print_testname("mixed read-write-lock");
- printk(" |");
+ pr_cont(" |");
dotest(rlock_AA2, FAILURE, LOCKTYPE_RWLOCK);
- printk(" |");
+ pr_cont(" |");
dotest(rsem_AA2, FAILURE, LOCKTYPE_RWSEM);
- printk("\n");
+ pr_cont("\n");

print_testname("mixed write-read-lock");
- printk(" |");
+ pr_cont(" |");
dotest(rlock_AA3, FAILURE, LOCKTYPE_RWLOCK);
- printk(" |");
+ pr_cont(" |");
dotest(rsem_AA3, FAILURE, LOCKTYPE_RWSEM);
- printk("\n");
+ pr_cont("\n");

printk(" --------------------------------------------------------------------------\n");