tests: More useful output of make check

Instead of spilling thousands of lines of output, make check now runs the
test-suite in about 100 lines or so.  If running under make check, the output of
tests is reduced. The MAKE_CHECK environment variable is used for this, so that
when running the test manually, the full output is still shown.  Furthermore,
pa_log is used consistently instead of printf, so that all test output goes to
stderr by default.  Colored output from make check goes to stdout.

20 files changed, 143 insertions, 114 deletions

diff --git a/configure.ac b/configure.ac
index 9322ca0d0..b6c9625dc 100644
--- a/configure.ac
+++ b/configure.ac
@@ -26,7 +26,7 @@ AC_INIT([pulseaudio],[m4_esyscmd(./git-version-gen .tarball-version)],[mzchyfrnh
 AC_CONFIG_SRCDIR([src/daemon/main.c])
 AC_CONFIG_MACRO_DIR([m4])
 AC_CONFIG_HEADERS([config.h])
-AM_INIT_AUTOMAKE([foreign 1.11 -Wall -Wno-portability silent-rules dist-xz tar-ustar])
+AM_INIT_AUTOMAKE([foreign 1.11 -Wall -Wno-portability silent-rules color-tests dist-xz tar-ustar])
 
 m4_define(pa_major, `echo $VERSION | cut -d. -f1 | cut -d- -f1`)
 m4_define(pa_minor, `echo $VERSION | cut -d. -f2 | cut -d- -f1`)
diff --git a/src/Makefile.am b/src/Makefile.am
index cc3e13b34..23e62030c 100644
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -289,6 +289,8 @@ TESTS_norun += \
 		alsa-time-test
 endif
 
+TESTS_ENVIRONMENT=MAKE_CHECK=1
+
 if BUILD_TESTS_DEFAULT
 noinst_PROGRAMS = $(TESTS) $(TESTS_norun)
 else
diff --git a/src/tests/asyncmsgq-test.c b/src/tests/asyncmsgq-test.c
index 96e5a0dff..9fbe5bc8f 100644
--- a/src/tests/asyncmsgq-test.c
+++ b/src/tests/asyncmsgq-test.c
@@ -49,19 +49,19 @@ static void the_thread(void *_q) {
         switch (code) {
 
             case OPERATION_A:
-                printf("Operation A\n");
+                pa_log_info("Operation A");
                 break;
 
             case OPERATION_B:
-                printf("Operation B\n");
+                pa_log_info("Operation B");
                 break;
 
             case OPERATION_C:
-                printf("Operation C\n");
+                pa_log_info("Operation C");
                 break;
 
             case QUIT:
-                printf("quit\n");
+                pa_log_info("quit");
                 quit = 1;
                 break;
         }
@@ -79,22 +79,22 @@ int main(int argc, char *argv[]) {
 
     pa_assert_se(t = pa_thread_new("test", the_thread, q));
 
-    printf("Operation A post\n");
+    pa_log_info("Operation A post");
     pa_asyncmsgq_post(q, NULL, OPERATION_A, NULL, 0, NULL, NULL);
 
     pa_thread_yield();
 
-    printf("Operation B post\n");
+    pa_log_info("Operation B post");
     pa_asyncmsgq_post(q, NULL, OPERATION_B, NULL, 0, NULL, NULL);
 
     pa_thread_yield();
 
-    printf("Operation C send\n");
+    pa_log_info("Operation C send");
     pa_asyncmsgq_send(q, NULL, OPERATION_C, NULL, 0, NULL);
 
     pa_thread_yield();
 
-    printf("Quit post\n");
+    pa_log_info("Quit post");
     pa_asyncmsgq_post(q, NULL, QUIT, NULL, 0, NULL, NULL);
 
     pa_thread_free(t);
diff --git a/src/tests/asyncq-test.c b/src/tests/asyncq-test.c
index 46bac9f42..6ac8cba68 100644
--- a/src/tests/asyncq-test.c
+++ b/src/tests/asyncq-test.c
@@ -36,12 +36,12 @@ static void producer(void *_q) {
     int i;
 
     for (i = 0; i < 1000; i++) {
-        printf("pushing %i\n", i);
+        pa_log_debug("pushing %i", i);
         pa_asyncq_push(q, PA_UINT_TO_PTR(i+1), 1);
     }
 
     pa_asyncq_push(q, PA_UINT_TO_PTR(-1), TRUE);
-    printf("pushed end\n");
+    pa_log_debug("pushed end");
 }
 
 static void consumer(void *_q) {
@@ -59,16 +59,19 @@ static void consumer(void *_q) {
 
         pa_assert(p == PA_UINT_TO_PTR(i+1));
 
-        printf("popped %i\n", i);
+        pa_log_debug("popped %i", i);
     }
 
-    printf("popped end\n");
+    pa_log_debug("popped end");
 }
 
 int main(int argc, char *argv[]) {
     pa_asyncq *q;
     pa_thread *t1, *t2;
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     pa_assert_se(q = pa_asyncq_new(0));
 
     pa_assert_se(t1 = pa_thread_new("producer", producer, q));
diff --git a/src/tests/get-binary-name-test.c b/src/tests/get-binary-name-test.c
index c35160fb4..7a09bc2c4 100644
--- a/src/tests/get-binary-name-test.c
+++ b/src/tests/get-binary-name-test.c
@@ -27,6 +27,8 @@
 #include <pulse/util.h>
 #include <pulse/xmalloc.h>
 
+#include <pulsecore/log.h>
+
 int main(int argc, char *argv[]) {
     char *exename;
     size_t allocated = 128;
@@ -35,13 +37,13 @@ int main(int argc, char *argv[]) {
         exename = pa_xmalloc(allocated);
 
         if (!pa_get_binary_name(exename, allocated)) {
-            printf("failed to read binary name\n");
+            pa_log_error("failed to read binary name");
             pa_xfree(exename);
             break;
         }
 
         if (strlen(exename) < allocated - 1) {
-            printf("%s\n", exename);
+            pa_log("%s", exename);
             pa_xfree(exename);
             return 0;
         }
diff --git a/src/tests/interpol-test.c b/src/tests/interpol-test.c
index 1a7c4b46a..ad00aca30 100644
--- a/src/tests/interpol-test.c
+++ b/src/tests/interpol-test.c
@@ -31,6 +31,7 @@
 #include <pulse/pulseaudio.h>
 #include <pulse/mainloop.h>
 
+#include <pulsecore/log.h>
 #include <pulsecore/macro.h>
 #include <pulsecore/thread.h>
 
@@ -118,7 +119,7 @@ static void context_state_callback(pa_context *c, void *userdata) {
             if (latency > 0)
                 flags |= PA_STREAM_ADJUST_LATENCY;
 
-            fprintf(stderr, "Connection established.\n");
+            pa_log("Connection established");
 
             pa_assert_se(stream = pa_stream_new(c, "interpol-test", &ss, NULL));
 
@@ -140,7 +141,7 @@ static void context_state_callback(pa_context *c, void *userdata) {
 
         case PA_CONTEXT_FAILED:
         default:
-            fprintf(stderr, "Context error: %s\n", pa_strerror(pa_context_errno(c)));
+            pa_log_error("Context error: %s", pa_strerror(pa_context_errno(c)));
             abort();
     }
 }
@@ -154,13 +155,11 @@ int main(int argc, char *argv[]) {
     pa_bool_t corked = FALSE;
 #endif
 
-    pa_log_set_level(PA_LOG_DEBUG);
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
 
     playback = argc <= 1 || !pa_streq(argv[1], "-r");
-
-    latency =
-        (argc >= 2 && !pa_streq(argv[1], "-r")) ? atoi(argv[1]) :
-        (argc >= 3 ? atoi(argv[2]) : 0);
+    latency = (argc >= 2 && !pa_streq(argv[1], "-r")) ? atoi(argv[1]) : (argc >= 3 ? atoi(argv[2]) : 0);
 
     /* Set up a new main loop */
     pa_assert_se(m = pa_threaded_mainloop_new());
@@ -214,7 +213,7 @@ int main(int argc, char *argv[]) {
             pa_bool_t cork_now;
 #endif
             rtc = pa_timeval_diff(&now, &start);
-            printf("%i\t%llu\t%llu\t%llu\t%llu\t%lli\t%u\t%u\t%llu\t%llu\n", k,
+            pa_log_info("%i\t%llu\t%llu\t%llu\t%llu\t%lli\t%u\t%u\t%llu\t%llu\n", k,
                    (unsigned long long) rtc,
                    (unsigned long long) t,
                    (unsigned long long) (rtc-old_rtc),
@@ -245,7 +244,6 @@ int main(int argc, char *argv[]) {
         }
 
         /* Spin loop, ugly but normal usleep() is just too badly grained */
-
         tv = now;
         while (pa_timeval_diff(pa_gettimeofday(&now), &tv) < 1000)
             pa_thread_yield();
diff --git a/src/tests/ipacl-test.c b/src/tests/ipacl-test.c
index 74bafd754..fa190cf0d 100644
--- a/src/tests/ipacl-test.c
+++ b/src/tests/ipacl-test.c
@@ -17,8 +17,9 @@
 #include <netinet/ip.h>
 #endif
 
-#include <pulsecore/socket.h>
+#include <pulsecore/log.h>
 #include <pulsecore/macro.h>
+#include <pulsecore/socket.h>
 #include <pulsecore/ipacl.h>
 #include <pulsecore/arpa-inet.h>
 
@@ -30,7 +31,7 @@ static void do_ip_acl_check(const char *s, int fd, int expected) {
     result = pa_ip_acl_check(acl, fd);
     pa_ip_acl_free(acl);
 
-    printf("%-20s result=%u (should be %u)\n", s, result, expected);
+    pa_log_info("%-20s result=%u (should be %u)", s, result, expected);
     pa_assert(result == expected);
 }
 
@@ -42,6 +43,9 @@ int main(int argc, char *argv[]) {
     int fd;
     int r;
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     fd = socket(PF_INET, SOCK_STREAM, 0);
     pa_assert(fd >= 0);
 
@@ -65,7 +69,7 @@ int main(int argc, char *argv[]) {
 
 #ifdef HAVE_IPV6
     if ( (fd = socket(PF_INET6, SOCK_STREAM, 0)) < 0 ) {
-      printf("Unable to open IPv6 socket, IPv6 tests ignored");
+      pa_log_error("Unable to open IPv6 socket, IPv6 tests ignored");
       return 0;
     }
 
diff --git a/src/tests/lock-autospawn-test.c b/src/tests/lock-autospawn-test.c
index 9ba61296d..e2db24ce0 100644
--- a/src/tests/lock-autospawn-test.c
+++ b/src/tests/lock-autospawn-test.c
@@ -103,7 +103,5 @@ int main(int argc, char**argv) {
     pa_thread_free(c);
     pa_thread_free(d);
 
-    pa_log("End");
-
     return 0;
 }
diff --git a/src/tests/memblock-test.c b/src/tests/memblock-test.c
index a36ce2257..b82c41aa9 100644
--- a/src/tests/memblock-test.c
+++ b/src/tests/memblock-test.c
@@ -24,33 +24,35 @@
 #include <stdio.h>
 #include <unistd.h>
 
+#include <pulse/xmalloc.h>
+
+#include <pulsecore/log.h>
 #include <pulsecore/memblock.h>
 #include <pulsecore/macro.h>
-#include <pulse/xmalloc.h>
 
 static void release_cb(pa_memimport *i, uint32_t block_id, void *userdata) {
-    printf("%s: Imported block %u is released.\n", (char*) userdata, block_id);
+    pa_log("%s: Imported block %u is released.", (char*) userdata, block_id);
 }
 
 static void revoke_cb(pa_memexport *e, uint32_t block_id, void *userdata) {
-    printf("%s: Exported block %u is revoked.\n", (char*) userdata, block_id);
+    pa_log("%s: Exported block %u is revoked.", (char*) userdata, block_id);
 }
 
 static void print_stats(pa_mempool *p, const char *text) {
     const pa_mempool_stat*s = pa_mempool_get_stat(p);
 
-    printf("%s = {\n"
-           "n_allocated = %u\n"
-           "n_accumulated = %u\n"
-           "n_imported = %u\n"
-           "n_exported = %u\n"
-           "allocated_size = %u\n"
-           "accumulated_size = %u\n"
-           "imported_size = %u\n"
-           "exported_size = %u\n"
-           "n_too_large_for_pool = %u\n"
-           "n_pool_full = %u\n"
-           "}\n",
+    pa_log_debug("%s = {\n"
+                 "\tn_allocated = %u\n"
+                 "\tn_accumulated = %u\n"
+                 "\tn_imported = %u\n"
+                 "\tn_exported = %u\n"
+                 "\tallocated_size = %u\n"
+                 "\taccumulated_size = %u\n"
+                 "\timported_size = %u\n"
+                 "\texported_size = %u\n"
+                 "\tn_too_large_for_pool = %u\n"
+                 "\tn_pool_full = %u\n"
+                 "}",
            text,
            (unsigned) pa_atomic_load(&s->n_allocated),
            (unsigned) pa_atomic_load(&s->n_accumulated),
@@ -78,6 +80,9 @@ int main(int argc, char *argv[]) {
 
     const char txt[] = "This is a test!";
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     pool_a = pa_mempool_new(TRUE, 0);
     pool_b = pa_mempool_new(TRUE, 0);
     pool_c = pa_mempool_new(TRUE, 0);
@@ -104,7 +109,7 @@ int main(int argc, char *argv[]) {
     blocks[4] = NULL;
 
     for (i = 0; blocks[i]; i++) {
-        printf("Memory block %u\n", i);
+        pa_log("Memory block %u", i);
 
         mb_a = blocks[i];
         pa_assert(mb_a);
@@ -123,7 +128,7 @@ int main(int argc, char *argv[]) {
         pa_assert(r >= 0);
         pa_assert(shm_id == id_a);
 
-        printf("A: Memory block exported as %u\n", id);
+        pa_log("A: Memory block exported as %u", id);
 
         mb_b = pa_memimport_get(import_b, id, shm_id, offset, size);
         pa_assert(mb_b);
@@ -132,12 +137,12 @@ int main(int argc, char *argv[]) {
         pa_assert(shm_id == id_a || shm_id == id_b);
         pa_memblock_unref(mb_b);
 
-        printf("B: Memory block exported as %u\n", id);
+        pa_log("B: Memory block exported as %u", id);
 
         mb_c = pa_memimport_get(import_c, id, shm_id, offset, size);
         pa_assert(mb_c);
         x = pa_memblock_acquire(mb_c);
-        printf("1 data=%s\n", x);
+        pa_log_debug("1 data=%s", x);
         pa_memblock_release(mb_c);
 
         print_stats(pool_a, "A");
@@ -146,7 +151,7 @@ int main(int argc, char *argv[]) {
 
         pa_memexport_free(export_b);
         x = pa_memblock_acquire(mb_c);
-        printf("2 data=%s\n", x);
+        pa_log_debug("2 data=%s", x);
         pa_memblock_release(mb_c);
         pa_memblock_unref(mb_c);
 
@@ -158,13 +163,13 @@ int main(int argc, char *argv[]) {
         pa_memexport_free(export_a);
     }
 
-    printf("vacuuming...\n");
+    pa_log("vacuuming...");
 
     pa_mempool_vacuum(pool_a);
     pa_mempool_vacuum(pool_b);
     pa_mempool_vacuum(pool_c);
 
-    printf("vacuuming done...\n");
+    pa_log("vacuuming done...");
 
     pa_mempool_free(pool_a);
     pa_mempool_free(pool_b);
diff --git a/src/tests/memblockq-test.c b/src/tests/memblockq-test.c
index 09d21420b..51e17176e 100644
--- a/src/tests/memblockq-test.c
+++ b/src/tests/memblockq-test.c
@@ -38,7 +38,7 @@ static void dump_chunk(const pa_memchunk *chunk) {
 
     q = pa_memblock_acquire(chunk->memblock);
     for (e = (char*) q + chunk->index, n = 0; n < chunk->length; n++, e++)
-        printf("%c", *e);
+        fprintf(stderr, "%c", *e);
     pa_memblock_release(chunk->memblock);
 }
 
@@ -48,14 +48,14 @@ static void dump(pa_memblockq *bq) {
     pa_assert(bq);
 
     /* First let's dump this as fixed block */
-    printf("FIXED >");
+    fprintf(stderr, "FIXED >");
     pa_memblockq_peek_fixed_size(bq, 64, &out);
     dump_chunk(&out);
     pa_memblock_unref(out.memblock);
-    printf("<\n");
+    fprintf(stderr, "<\n");
 
     /* Then let's dump the queue manually */
-    printf("MANUAL>");
+    fprintf(stderr, "MANUAL>");
 
     for (;;) {
         if (pa_memblockq_peek(bq, &out) < 0)
@@ -66,7 +66,7 @@ static void dump(pa_memblockq *bq) {
         pa_memblockq_drop(bq, out.length);
     }
 
-    printf("<\n");
+    fprintf(stderr, "<\n");
 }
 
 int main(int argc, char *argv[]) {
diff --git a/src/tests/mix-test.c b/src/tests/mix-test.c
index 7c05b8ed3..19b5ea5ab 100644
--- a/src/tests/mix-test.c
+++ b/src/tests/mix-test.c
@@ -35,6 +35,9 @@ static void dump_block(const pa_sample_spec *ss, const pa_memchunk *chunk) {
     void *d;
     unsigned i;
 
+    if (getenv("MAKE_CHECK"))
+        return;
+
     d = pa_memblock_acquire(chunk->memblock);
 
     switch (ss->format) {
@@ -202,7 +205,8 @@ int main(int argc, char *argv[]) {
     pa_sample_spec a;
     pa_cvolume v;
 
-    pa_log_set_level(PA_LOG_DEBUG);
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
 
     pa_assert_se(pool = pa_mempool_new(FALSE, 0));
 
@@ -217,7 +221,7 @@ int main(int argc, char *argv[]) {
         pa_mix_info m[2];
         void *ptr;
 
-        printf("=== mixing: %s\n", pa_sample_format_to_string(a.format));
+        pa_log_debug("=== mixing: %s\n", pa_sample_format_to_string(a.format));
 
         /* Generate block */
         i.memblock = generate_block(pool, &a);
diff --git a/src/tests/once-test.c b/src/tests/once-test.c
index 8a9995dad..b1ef6ba9d 100644
--- a/src/tests/once-test.c
+++ b/src/tests/once-test.c
@@ -61,7 +61,7 @@ static void thread_func(void *data) {
     pa_assert_se(pthread_setaffinity_np(pthread_self(), sizeof(mask), &mask) == 0);
 #endif
 
-    /* pa_log("started up: %s", data); */
+    pa_log_debug("started up: %s", (char *) data);
 
     r = pthread_barrier_wait(&barrier);
     pa_assert(r == 0 || r == PTHREAD_BARRIER_SERIAL_THREAD);
@@ -73,6 +73,9 @@ static void thread_func(void *data) {
 int main(int argc, char *argv[]) {
     unsigned n, i;
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     n_cpu = pa_ncpus();
 
     for (n = 0; n < N_ITERATIONS; n++) {
@@ -92,7 +95,7 @@ int main(int argc, char *argv[]) {
             pa_thread_join(threads[i]);
 
         pa_assert(n_run == 1);
-        pa_log("ran by %s", ran_by);
+        pa_log_info("ran by %s", ran_by);
 
         for (i = 0; i < N_THREADS; i++) {
             pa_xfree(pa_thread_get_data(threads[i]));
diff --git a/src/tests/prioq-test.c b/src/tests/prioq-test.c
index 120b512bc..bbcc92aa3 100644
--- a/src/tests/prioq-test.c
+++ b/src/tests/prioq-test.c
@@ -3,6 +3,7 @@
 #endif
 
 #include <pulsecore/prioq.h>
+#include <pulsecore/log.h>
 #include <pulsecore/macro.h>
 
 #define N 1024
@@ -13,6 +14,9 @@ int main(int argc, char *argv[]) {
 
     srand(0);
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     q = pa_prioq_new(pa_idxset_trivial_compare_func);
 
     /* Fill in 1024 */
@@ -22,20 +26,19 @@ int main(int argc, char *argv[]) {
     /* Remove half of it again */
     for (i = 0; i < N/2; i++){
         unsigned u = PA_PTR_TO_UINT(pa_prioq_pop(q));
-        pa_log("%16u", u);
+        pa_log_debug("%16u", u);
     }
 
-    pa_log("Refilling");
+    pa_log_debug("Refilling");
 
     /* Fill in another 1024 */
     for (i = 0; i < N; i++)
         pa_prioq_put(q, PA_UINT_TO_PTR((unsigned) rand()));
 
-
     /* Remove everything */
     while (!pa_prioq_isempty(q)) {
         unsigned u = PA_PTR_TO_UINT(pa_prioq_pop(q));
-        pa_log("%16u", u);
+        pa_log_debug("%16u", u);
     }
 
     pa_prioq_free(q, NULL, NULL);
diff --git a/src/tests/proplist-test.c b/src/tests/proplist-test.c
index 8b5a23537..f5a54d65d 100644
--- a/src/tests/proplist-test.c
+++ b/src/tests/proplist-test.c
@@ -36,6 +36,9 @@ int main(int argc, char*argv[]) {
     const char *text;
     const char *x[] = { "foo", NULL };
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     a = pa_proplist_new();
     pa_assert_se(pa_proplist_sets(a, PA_PROP_MEDIA_TITLE, "Brandenburgische Konzerte") == 0);
     pa_assert_se(pa_proplist_sets(a, PA_PROP_MEDIA_ARTIST, "Johann Sebastian Bach") == 0);
@@ -48,12 +51,12 @@ int main(int argc, char*argv[]) {
 
     pa_assert_se(!pa_proplist_gets(a, PA_PROP_MEDIA_ICON));
 
-    printf("%s\n", pa_strnull(pa_proplist_gets(a, PA_PROP_MEDIA_TITLE)));
+    pa_log_debug("%s", pa_strnull(pa_proplist_gets(a, PA_PROP_MEDIA_TITLE)));
     pa_assert_se(pa_proplist_unset(b, PA_PROP_MEDIA_TITLE) == 0);
 
     s = pa_proplist_to_string(a);
     t = pa_proplist_to_string(b);
-    printf("---\n%s---\n%s", s, t);
+    pa_log_debug("---\n%s---\n%s", s, t);
 
     c = pa_proplist_from_string(s);
     u = pa_proplist_to_string(c);
@@ -69,16 +72,16 @@ int main(int argc, char*argv[]) {
 
     text = "  eins = zwei drei = \"\\\"vier\\\"\" fuenf=sechs sieben ='\\a\\c\\h\\t\\'\\\"' neun= hex:0123456789abCDef ";
 
-    printf("%s\n", text);
+    pa_log_debug("%s", text);
     d = pa_proplist_from_string(text);
     v = pa_proplist_to_string(d);
     pa_proplist_free(d);
-    printf("%s\n", v);
+    pa_log_debug("%s", v);
     d = pa_proplist_from_string(v);
     pa_xfree(v);
     v = pa_proplist_to_string(d);
     pa_proplist_free(d);
-    printf("%s\n", v);
+    pa_log_debug("%s", v);
     pa_xfree(v);
 
     pa_assert_se(ma = pa_modargs_new("foo='foobar=waldo foo2=\"lj\\\"dhflh\" foo3=\"kjlskj\\'\"'", x));
@@ -86,7 +89,7 @@ int main(int argc, char*argv[]) {
 
     pa_assert_se(pa_modargs_get_proplist(ma, "foo", a, PA_UPDATE_REPLACE) >= 0);
 
-    printf("%s\n", v = pa_proplist_to_string(a));
+    pa_log_debug("%s", v = pa_proplist_to_string(a));
     pa_xfree(v);
 
     pa_proplist_free(a);
diff --git a/src/tests/resampler-test.c b/src/tests/resampler-test.c
index 12d06d271..ebd6fddd7 100644
--- a/src/tests/resampler-test.c
+++ b/src/tests/resampler-test.c
@@ -32,6 +32,7 @@
 #include <pulse/volume.h>
 
 #include <pulsecore/i18n.h>
+#include <pulsecore/log.h>
 #include <pulsecore/resampler.h>
 #include <pulsecore/macro.h>
 #include <pulsecore/endianmacros.h>
@@ -39,10 +40,14 @@
 #include <pulsecore/sample-util.h>
 #include <pulsecore/core-util.h>
 
-static void dump_block(const pa_sample_spec *ss, const pa_memchunk *chunk) {
+static void dump_block(const char *label, const pa_sample_spec *ss, const pa_memchunk *chunk) {
     void *d;
     unsigned i;
 
+    if (getenv("MAKE_CHECK"))
+        return;
+    printf("%s:  \t", label);
+
     d = pa_memblock_acquire(chunk->memblock);
 
     switch (ss->format) {
@@ -296,7 +301,7 @@ static void dump_resample_methods(void) {
 int main(int argc, char *argv[]) {
     pa_mempool *pool = NULL;
     pa_sample_spec a, b;
-    int ret = 1, verbose = 0, c;
+    int ret = 1, c;
     pa_bool_t all_formats = TRUE;
     pa_resample_method_t method;
     int seconds;
@@ -320,7 +325,9 @@ int main(int argc, char *argv[]) {
     setlocale(LC_ALL, "");
     bindtextdomain(GETTEXT_PACKAGE, PULSE_LOCALEDIR);
 
-    pa_log_set_level(PA_LOG_DEBUG);
+    pa_log_set_level(PA_LOG_WARN);
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_INFO);
 
     pa_assert_se(pool = pa_mempool_new(FALSE, 0));
 
@@ -341,7 +348,6 @@ int main(int argc, char *argv[]) {
 
             case 'v':
                 pa_log_set_level(PA_LOG_DEBUG);
-                verbose = 1;
                 break;
 
             case ARG_VERSION:
@@ -407,16 +413,14 @@ int main(int argc, char *argv[]) {
         pa_memchunk i, j;
         pa_usec_t ts;
 
-        if (verbose) {
-            printf(_("Compilation CFLAGS: %s\n"), PA_CFLAGS);
-            printf(_("=== %d seconds: %d Hz %d ch (%s) -> %d Hz %d ch (%s)\n"), seconds,
+        pa_log_debug(_("Compilation CFLAGS: %s"), PA_CFLAGS);
+        pa_log_debug(_("=== %d seconds: %d Hz %d ch (%s) -> %d Hz %d ch (%s)"), seconds,
                    a.rate, a.channels, pa_sample_format_to_string(a.format),
                    b.rate, b.channels, pa_sample_format_to_string(b.format));
-        }
 
         ts = pa_rtclock_now();
         pa_assert_se(resampler = pa_resampler_new(pool, &a, NULL, &b, NULL, method, 0));
-        printf("init: %llu\n", (long long unsigned)(pa_rtclock_now() - ts));
+        pa_log_info("init: %llu", (long long unsigned)(pa_rtclock_now() - ts));
 
         i.memblock = pa_memblock_new(pool, pa_usec_to_bytes(1*PA_USEC_PER_SEC, &a));
 
@@ -427,7 +431,7 @@ int main(int argc, char *argv[]) {
             pa_resampler_run(resampler, &i, &j);
             pa_memblock_unref(j.memblock);
         }
-        printf("resampling: %llu\n", (long long unsigned)(pa_rtclock_now() - ts));
+        pa_log_info("resampling: %llu", (long long unsigned)(pa_rtclock_now() - ts));
         pa_memblock_unref(i.memblock);
 
         pa_resampler_free(resampler);
@@ -440,8 +444,7 @@ int main(int argc, char *argv[]) {
             pa_resampler *forth, *back;
             pa_memchunk i, j, k;
 
-            if (verbose)
-                printf("=== %s -> %s -> %s -> /2\n",
+            pa_log_debug("=== %s -> %s -> %s -> /2",
                        pa_sample_format_to_string(a.format),
                        pa_sample_format_to_string(b.format),
                        pa_sample_format_to_string(a.format));
@@ -455,12 +458,9 @@ int main(int argc, char *argv[]) {
             pa_resampler_run(forth, &i, &j);
             pa_resampler_run(back, &j, &k);
 
-            printf("before:  ");
-            dump_block(&a, &i);
-            printf("after :  ");
-            dump_block(&b, &j);
-            printf("reverse: ");
-            dump_block(&a, &k);
+            dump_block("before", &a, &i);
+            dump_block("after", &b, &j);
+            dump_block("reverse", &a, &k);
 
             pa_memblock_unref(i.memblock);
             pa_memblock_unref(j.memblock);
diff --git a/src/tests/smoother-test.c b/src/tests/smoother-test.c
index 2cc9f58b2..4471669c5 100644
--- a/src/tests/smoother-test.c
+++ b/src/tests/smoother-test.c
@@ -24,9 +24,11 @@
 #include <stdio.h>
 #include <stdlib.h>
 
-#include <pulsecore/time-smoother.h>
 #include <pulse/timeval.h>
 
+#include <pulsecore/log.h>
+#include <pulsecore/time-smoother.h>
+
 int main(int argc, char*argv[]) {
     pa_usec_t x;
     unsigned u = 0;
@@ -45,7 +47,8 @@ int main(int argc, char*argv[]) {
 
     srand(0);
 
-    pa_log_set_level(PA_LOG_DEBUG);
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
 
     for (m = 0, u = 0; u < PA_ELEMENTSOF(msec); u+= 2) {
 
@@ -67,13 +70,13 @@ int main(int argc, char*argv[]) {
 
         while (u < PA_ELEMENTSOF(msec) && (pa_usec_t) msec[u]*PA_USEC_PER_MSEC < x) {
             pa_smoother_put(s, (pa_usec_t) msec[u] * PA_USEC_PER_MSEC, (pa_usec_t) msec[u+1] * PA_USEC_PER_MSEC);
-            printf("%i\t\t%i\n", msec[u],  msec[u+1]);
+            pa_log_debug("%i\t\t%i", msec[u],  msec[u+1]);
             u += 2;
 
             pa_smoother_resume(s, (pa_usec_t) msec[u] * PA_USEC_PER_MSEC, TRUE);
         }
 
-        printf("%llu\t%llu\n", (unsigned long long) (x/PA_USEC_PER_MSEC), (unsigned long long) (pa_smoother_get(s, x)/PA_USEC_PER_MSEC));
+        pa_log_debug("%llu\t%llu", (unsigned long long) (x/PA_USEC_PER_MSEC), (unsigned long long) (pa_smoother_get(s, x)/PA_USEC_PER_MSEC));
     }
 
     pa_smoother_free(s);
diff --git a/src/tests/thread-mainloop-test.c b/src/tests/thread-mainloop-test.c
index 722759726..599f1959b 100644
--- a/src/tests/thread-mainloop-test.c
+++ b/src/tests/thread-mainloop-test.c
@@ -67,8 +67,6 @@ int main(int argc, char *argv[]) {
     fprintf(stderr, "waiting 5s (sleep)\n");
     pa_msleep(5000);
 
-    fprintf(stderr, "shutting down\n");
-
     pa_threaded_mainloop_stop(m);
 
     pa_threaded_mainloop_free(m);
diff --git a/src/tests/thread-test.c b/src/tests/thread-test.c
index aaa79fb58..6441dc7e0 100644
--- a/src/tests/thread-test.c
+++ b/src/tests/thread-test.c
@@ -46,14 +46,14 @@ static pa_once once = PA_ONCE_INIT;
 static void thread_func(void *data) {
     pa_tls_set(tls, data);
 
-    pa_log("thread_func() for %s starting...", (char*) pa_tls_get(tls));
+    pa_log_info("thread_func() for %s starting...", (char*) pa_tls_get(tls));
 
     pa_mutex_lock(mutex);
 
     for (;;) {
         int k, n;
 
-        pa_log("%s waiting ...", (char*) pa_tls_get(tls));
+        pa_log_info("%s waiting ...", (char*) pa_tls_get(tls));
 
         for (;;) {
 
@@ -75,7 +75,7 @@ static void thread_func(void *data) {
 
         pa_cond_signal(cond2, 0);
 
-        pa_log("%s got number %i", (char*) pa_tls_get(tls), k);
+        pa_log_info("%s got number %i", (char*) pa_tls_get(tls), k);
 
         /* Spin! */
         for (n = 0; n < k; n++)
@@ -88,13 +88,16 @@ quit:
 
     pa_mutex_unlock(mutex);
 
-    pa_log("thread_func() for %s done...", (char*) pa_tls_get(tls));
+    pa_log_info("thread_func() for %s done...", (char*) pa_tls_get(tls));
 }
 
 int main(int argc, char *argv[]) {
     int i, k;
     pa_thread* t[THREADS_MAX];
 
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
     mutex = pa_mutex_new(FALSE, FALSE);
     cond1 = pa_cond_new();
     cond2 = pa_cond_new();
@@ -113,7 +116,7 @@ int main(int argc, char *argv[]) {
 
         magic_number = (int) rand() % 0x10000;
 
-        pa_log("iteration %i (%i)", k, magic_number);
+        pa_log_info("iteration %i (%i)", k, magic_number);
 
         pa_cond_signal(cond1, 0);
 
diff --git a/src/tests/utf8-test.c b/src/tests/utf8-test.c
index f1708ad4c..6dc5b50dc 100644
--- a/src/tests/utf8-test.c
+++ b/src/tests/utf8-test.c
@@ -13,11 +13,11 @@ int main(int argc, char *argv[]) {
     assert(pa_utf8_valid("hallo\n"));
     assert(pa_utf8_valid("hüpfburg\n"));
 
-    printf("LATIN1: %s\n", c = pa_utf8_filter("hüpfburg"));
+    fprintf(stderr, "LATIN1: %s\n", c = pa_utf8_filter("hüpfburg"));
     pa_xfree(c);
-    printf("UTF8: %sx\n", c = pa_utf8_filter("hüpfburg"));
+    fprintf(stderr, "UTF8: %sx\n", c = pa_utf8_filter("hüpfburg"));
     pa_xfree(c);
-    printf("LATIN1: %sx\n", c = pa_utf8_filter("üxknärzmörzeltörszß³§dsjkfh"));
+    fprintf(stderr, "LATIN1: %sx\n", c = pa_utf8_filter("üxknärzmörzeltörszß³§dsjkfh"));
     pa_xfree(c);
 
     return 0;
diff --git a/src/tests/voltest.c b/src/tests/voltest.c
index b45a46830..f7405ffe6 100644
--- a/src/tests/voltest.c
+++ b/src/tests/voltest.c
@@ -26,6 +26,7 @@
 
 #include <pulse/volume.h>
 
+#include <pulsecore/log.h>
 #include <pulsecore/macro.h>
 
 int main(int argc, char *argv[]) {
@@ -36,15 +37,18 @@ int main(int argc, char *argv[]) {
     pa_volume_t md = 0;
     unsigned mdn = 0;
 
-    printf("Attenuation of sample 1 against 32767: %g dB\n", 20.0*log10(1.0/32767.0));
-    printf("Smallest possible attenuation > 0 applied to 32767: %li\n", lrint(32767.0*pa_sw_volume_to_linear(1)));
+    if (!getenv("MAKE_CHECK"))
+        pa_log_set_level(PA_LOG_DEBUG);
+
+    pa_log("Attenuation of sample 1 against 32767: %g dB", 20.0*log10(1.0/32767.0));
+    pa_log("Smallest possible attenuation > 0 applied to 32767: %li", lrint(32767.0*pa_sw_volume_to_linear(1)));
 
     for (v = PA_VOLUME_MUTED; v <= PA_VOLUME_NORM*2; v += 256) {
 
         double dB = pa_sw_volume_to_dB(v);
         double f = pa_sw_volume_to_linear(v);
 
-        printf("Volume: %3i; percent: %i%%; decibel %0.2f; linear = %0.2f; volume(decibel): %3i; volume(linear): %3i\n",
+        pa_log_debug("Volume: %3i; percent: %i%%; decibel %0.2f; linear = %0.2f; volume(decibel): %3i; volume(linear): %3i",
                v, (v*100)/PA_VOLUME_NORM, dB, f, pa_sw_volume_from_dB(dB), pa_sw_volume_from_linear(f));
     }
 
@@ -53,11 +57,7 @@ int main(int argc, char *argv[]) {
 
         pa_cvolume_set(&cv, 2, v);
 
-        printf("Volume: %3i [%s] [%s]\n",
-               v,
-               pa_cvolume_snprint(s, sizeof(s), &cv),
-               pa_sw_cvolume_snprint_dB(t, sizeof(t), &cv));
-
+        pa_log_debug("Volume: %3i [%s] [%s]", v, pa_cvolume_snprint(s, sizeof(s), &cv), pa_sw_cvolume_snprint_dB(t, sizeof(t), &cv));
     }
 
     map.channels = cv.channels = 2;
@@ -68,7 +68,7 @@ int main(int argc, char *argv[]) {
         for (cv.values[1] = PA_VOLUME_MUTED; cv.values[1] <= PA_VOLUME_NORM*2; cv.values[1] += 4096) {
             char s[PA_CVOLUME_SNPRINT_MAX];
 
-            printf("Volume: [%s]; balance: %2.1f\n", pa_cvolume_snprint(s, sizeof(s), &cv), pa_cvolume_get_balance(&cv, &map));
+            pa_log_debug("Volume: [%s]; balance: %2.1f", pa_cvolume_snprint(s, sizeof(s), &cv), pa_cvolume_get_balance(&cv, &map));
         }
 
     for (cv.values[0] = PA_VOLUME_MUTED+4096; cv.values[0] <= PA_VOLUME_NORM*2; cv.values[0] += 4096)
@@ -78,13 +78,13 @@ int main(int argc, char *argv[]) {
                 pa_cvolume r;
                 float k;
 
-                printf("Before: volume: [%s]; balance: %2.1f\n", pa_cvolume_snprint(s, sizeof(s), &cv), pa_cvolume_get_balance(&cv, &map));
+                pa_log_debug("Before: volume: [%s]; balance: %2.1f", pa_cvolume_snprint(s, sizeof(s), &cv), pa_cvolume_get_balance(&cv, &map));
 
                 r = cv;
                 pa_cvolume_set_balance(&r, &map,b);
 
                 k = pa_cvolume_get_balance(&r, &map);
-                printf("After: volume: [%s]; balance: %2.1f (intended: %2.1f) %s\n", pa_cvolume_snprint(s, sizeof(s), &r), k, b, k < b-.05 || k > b+.5 ? "MISMATCH" : "");
+                pa_log_debug("After: volume: [%s]; balance: %2.1f (intended: %2.1f) %s", pa_cvolume_snprint(s, sizeof(s), &r), k, b, k < b-.05 || k > b+.5 ? "MISMATCH" : "");
             }
 
     for (v = PA_VOLUME_MUTED; v <= PA_VOLUME_NORM*2; v += 51) {
@@ -125,7 +125,7 @@ int main(int argc, char *argv[]) {
         }
     }
 
-    printf("max deviation: %lu n=%lu\n", (unsigned long) md, (unsigned long) mdn);
+    pa_log("max deviation: %lu n=%lu", (unsigned long) md, (unsigned long) mdn);
 
     pa_assert(md <= 1);
     pa_assert(mdn <= 251);