tests: sprinkle igt logging

All the cases that simply dump some debug information and couldn't be
converted to some of the fancier macros.

Some information output removed when it's redundant with the subtest
status.

Signed-off-by: Daniel Vetter <daniel.vetter@ffwll.ch>

tests/drv_suspend.c

@@ -82,11 +82,11 @@ test_fence_restore(int fd, bool tiled2untiled)
 
 	igt_system_suspend_autoresume();
 
-	printf("checking the first canary object\n");
+	igt_info("checking the first canary object\n");
 	for (i = 0; i < OBJECT_SIZE/sizeof(uint32_t); i++)
 		igt_assert(ptr1[i] == i);
 
-	printf("checking the second canary object\n");
+	igt_info("checking the second canary object\n");
 	for (i = 0; i < OBJECT_SIZE/sizeof(uint32_t); i++)
 		igt_assert(ptr2[i] == i);
 

tests/gem_bad_length.c

@@ -70,7 +70,7 @@ static int gem_exec(int fd, struct drm_i915_gem_execbuffer2 *execbuf)
 static void create0(int fd)
 {
 	int retval = 0;
-	printf("trying to create a zero-length gem object\n");
+	igt_info("trying to create a zero-length gem object\n");
 	do_gem_create(fd, 0, &retval);
 	igt_assert(retval == EINVAL);
 }
@@ -109,7 +109,7 @@ static void exec0(int fd)
 	i915_execbuffer2_set_context_id(execbuf, 0);
 	execbuf.rsvd2 = 0;
 
-	printf("trying to run an empty batchbuffer\n");
+	igt_info("trying to run an empty batchbuffer\n");
 	gem_exec(fd, &execbuf);
 
 	gem_close(fd, exec[0].handle);

tests/gem_basic.c

@@ -44,7 +44,7 @@ test_bad_close(int fd)
 	struct drm_gem_close close_bo;
 	int ret;
 
-	printf("Testing error return on bad close ioctl.\n");
+	igt_info("Testing error return on bad close ioctl.\n");
 
 	close_bo.handle = 0x10101010;
 	ret = ioctl(fd, DRM_IOCTL_GEM_CLOSE, &close_bo);
@@ -57,7 +57,7 @@ test_create_close(int fd)
 {
 	uint32_t handle;
 
-	printf("Testing creating and closing an object.\n");
+	igt_info("Testing creating and closing an object.\n");
 
 	handle = gem_create(fd, 16*1024);
 
@@ -67,7 +67,7 @@ test_create_close(int fd)
 static void
 test_create_fd_close(int fd)
 {
-	printf("Testing closing with an object allocated.\n");
+	igt_info("Testing closing with an object allocated.\n");
 
 	gem_create(fd, 16*1024);
 	/* leak it */

tests/gem_caching.c

@@ -127,7 +127,7 @@ igt_main
 			flags &= ~TEST_READ;
 		if (IS_BROADWATER(devid) || IS_CRESTLINE(devid)) {
 			/* chipset is completely fubar */
-			printf("coherency broken on i965g/gm\n");
+			igt_info("coherency broken on i965g/gm\n");
 			flags = 0;
 		}
 
@@ -147,7 +147,7 @@ igt_main
 	igt_subtest("reads") {
 		igt_require(flags & TEST_READ);
 
-		printf("checking partial reads\n");
+		igt_info("checking partial reads\n");
 
 		for (i = 0; i < ROUNDS; i++) {
 			uint8_t val0 = i;
@@ -174,7 +174,7 @@ igt_main
 	igt_subtest("writes") {
 		igt_require(flags & TEST_WRITE);
 
-		printf("checking partial writes\n");
+		igt_info("checking partial writes\n");
 
 		for (i = 0; i < ROUNDS; i++) {
 			uint8_t val0 = i, val1;
@@ -219,7 +219,7 @@ igt_main
 	igt_subtest("read-writes") {
 		igt_require((flags & TEST_BOTH) == TEST_BOTH);
 
-		printf("checking partial writes after partial reads\n");
+		igt_info("checking partial writes after partial reads\n");
 
 		for (i = 0; i < ROUNDS; i++) {
 			uint8_t val0 = i, val1, val2;

tests/gem_concurrent_blit.c

@@ -390,7 +390,7 @@ igt_main
 		if (num_buffers > max)
 			num_buffers = max;
 		num_buffers /= 2;
-		printf("using 2x%d buffers, each 1MiB\n", num_buffers);
+		igt_info("using 2x%d buffers, each 1MiB\n", num_buffers);
 	}
 
 	for (i = 0; i < ARRAY_SIZE(access_modes); i++)

tests/gem_cpu_reloc.c

@@ -242,6 +242,6 @@ igt_simple_main
 		igt_progress("gem_cpu_reloc: ", 2*count+i, 3*count);
 	}
 
-	printf("Test suceeded, cleanup up - this might take a while.\n");
+	igt_info("Test suceeded, cleanup up - this might take a while.\n");
 	close(fd);
 }

tests/gem_cs_prefetch.c

@@ -162,7 +162,7 @@ igt_simple_main
 		igt_progress("gem_cs_prefetch: ", i, count);
 	}
 
-	printf("Test suceeded, cleanup up - this might take a while.\n");
+	igt_info("Test suceeded, cleanup up - this might take a while.\n");
 	drm_intel_bufmgr_destroy(bufmgr);
 
 	close(fd);

tests/gem_ctx_exec.c

@@ -150,10 +150,10 @@ static void big_exec(int fd, uint32_t handle, int ring)
 		gem_close(fd, gem_exec[i].handle);
 		gem_exec[i].handle = handle;
 		execbuf.buffer_count--;
-		printf("trying buffer count %i\n", i - 1);
+		igt_info("trying buffer count %i\n", i - 1);
 	}
 
-	printf("reduced buffer count to %i from %i\n",
+	igt_info("reduced buffer count to %i from %i\n",
 	       i - 1, num_buffers);
 
 	/* double check that it works */

tests/gem_dummy_reloc_loop.c

@@ -206,7 +206,7 @@ igt_main
 			unsigned int target_flink;
 			char buffer_name[32];
 			if (dri_bo_flink(target_buffer, &target_flink)) {
-				printf("fail to get flink for target buffer\n");
+				igt_info("fail to get flink for target buffer\n");
 				igt_assert_f(0, "fail to create global "
 					     "gem_handle for target buffer\n");
 			}
@@ -237,52 +237,52 @@ igt_main
 	}
 
 	igt_subtest("render") {
-		printf("running dummy loop on render\n");
+		igt_info("running dummy loop on render\n");
 		dummy_reloc_loop(I915_EXEC_RENDER);
-		printf("dummy loop run on render completed\n");
+		igt_info("dummy loop run on render completed\n");
 	}
 
 	igt_subtest("bsd") {
 		gem_require_ring(fd, I915_EXEC_BSD);
 		sleep(2);
-		printf("running dummy loop on bsd\n");
+		igt_info("running dummy loop on bsd\n");
 		dummy_reloc_loop(I915_EXEC_BSD);
-		printf("dummy loop run on bsd completed\n");
+		igt_info("dummy loop run on bsd completed\n");
 	}
 
 	igt_subtest("blt") {
 		gem_require_ring(fd, I915_EXEC_BLT);
 		sleep(2);
-		printf("running dummy loop on blt\n");
+		igt_info("running dummy loop on blt\n");
 		dummy_reloc_loop(I915_EXEC_BLT);
-		printf("dummy loop run on blt completed\n");
+		igt_info("dummy loop run on blt completed\n");
 	}
 
 #ifdef I915_EXEC_VEBOX
 	igt_subtest("vebox") {
 		gem_require_ring(fd, I915_EXEC_VEBOX);
 		sleep(2);
-		printf("running dummy loop on vebox\n");
+		igt_info("running dummy loop on vebox\n");
 		dummy_reloc_loop(LOCAL_I915_EXEC_VEBOX);
-		printf("dummy loop run on vebox completed\n");
+		igt_info("dummy loop run on vebox completed\n");
 	}
 #endif
 
 	igt_subtest("mixed") {
 		if (num_rings > 1) {
 			sleep(2);
-			printf("running dummy loop on random rings\n");
+			igt_info("running dummy loop on random rings\n");
 			dummy_reloc_loop_random_ring(num_rings);
-			printf("dummy loop run on random rings completed\n");
+			igt_info("dummy loop run on random rings completed\n");
 		}
 	}
 	igt_subtest("mixed_multi_fd") {
 		if (num_rings > 1) {
 			sleep(2);
-			printf("running dummy loop on random rings based on "
+			igt_info("running dummy loop on random rings based on "
 					"multi drm_fd\n");
 			dummy_reloc_loop_random_ring_multi_fd(num_rings);
-			printf("dummy loop run on random rings based on "
+			igt_info("dummy loop run on random rings based on "
 					"multi drm_fd completed\n");
 		}
 	}

tests/gem_exec_blt.c

@@ -242,10 +242,10 @@ static void run(int object_size)
 			gem_execbuf(fd, &execbuf);
 		gem_sync(fd, handle);
 		gettimeofday(&end, NULL);
-		printf("Time to blt %d bytes x %6d:	%7.3fµs, %s\n",
+		igt_info("Time to blt %d bytes x %6d:	%7.3fµs, %s\n",
-		       object_size, count,
+			 object_size, count,
-		       elapsed(&start, &end, count),
+			 elapsed(&start, &end, count),
-		       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+			 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 		fflush(stdout);
 	}
 	gem_close(fd, handle);

tests/gem_exec_lut_handle.c

@@ -170,7 +170,7 @@ igt_simple_main
 				elapsed[i][1] = ELAPSED(&start, &end);
 			}
 
-			printf("%s: buffers=%4d:", p->name, n);
+			igt_info("%s: buffers=%4d:", p->name, n);
 
 			s_x = s_y = s_xx = s_xy = 0;
 			for (j = 0; j < i; j++) {
@@ -182,7 +182,7 @@ igt_simple_main
 			}
 			B = (s_xy - s_x * s_y / j) / (s_xx - s_x * s_x / j);
 			A = s_y / j - B * s_x / j;
-			printf(" old=%7.0f + %.1f*reloc,", A, B);
+			igt_info(" old=%7.0f + %.1f*reloc,", A, B);
 
 			s_x = s_y = s_xx = s_xy = 0;
 			for (j = 0; j < i; j++) {
@@ -194,9 +194,9 @@ igt_simple_main
 			}
 			B = (s_xy - s_x * s_y / j) / (s_xx - s_x * s_x / j);
 			A = s_y / j - B * s_x / j;
-			printf(" lut=%7.0f + %.1f*reloc (ns)", A, B);
+			igt_info(" lut=%7.0f + %.1f*reloc (ns)", A, B);
 
-			printf("\n");
+			igt_info("\n");
 		}
 	}
 }

tests/gem_exec_nop.c

@@ -99,8 +99,8 @@ static void loop(int fd, uint32_t handle, unsigned ring_id, const char *ring_nam
 		gettimeofday(&start, NULL);
 		igt_assert(exec(fd, handle, count, ring_id) == 0);
 		gettimeofday(&end, NULL);
-		printf("Time to exec x %d:		%7.3fµs (ring=%s)\n",
+		igt_info("Time to exec x %d:		%7.3fµs (ring=%s)\n",
-		       count, elapsed(&start, &end, count), ring_name);
+			 count, elapsed(&start, &end, count), ring_name);
 		fflush(stdout);
 	}
 }

tests/gem_fd_exhaustion.c

@@ -49,7 +49,7 @@ igt_simple_main
 	igt_assert(fscanf(file_max, "%u", &nofile_rlim) == 1);
 	fclose(file_max);
 
-	printf("System limit for open files is %u\n", nofile_rlim);
+	igt_info("System limit for open files is %u\n", nofile_rlim);
 
 	igt_assert(getrlimit(RLIMIT_NOFILE, &rlim) == 0);
 	rlim.rlim_cur = nofile_rlim;
@@ -78,7 +78,7 @@ igt_simple_main
 			if (tmp_fd < 0) {
 				/* Ensure we actually hit the failure path ... */
 				igt_assert(handle == 0);
-				printf("fd exhaustion after %i rounds.\n", i);
+				igt_info("fd exhaustion after %i rounds.\n", i);
 				break;
 			}
 		}

tests/gem_fence_thrash.c

@@ -175,9 +175,9 @@ static int run_test(int threads_per_fence, void *f, int tiling,
 
 	num_threads = threads_per_fence * num_fences;
 
-	printf("%s: threads %d, fences %d, tiling %d, surfaces per thread %d\n",
+	igt_info("%s: threads %d, fences %d, tiling %d, surfaces per thread %d\n",
-	       f == bo_copy ? "copy" : "write-verify", num_threads,
+		 f == bo_copy ? "copy" : "write-verify", num_threads,
-	       num_fences, tiling, surfaces_per_thread);
+		 num_fences, tiling, surfaces_per_thread);
 
 	if (threads_per_fence) {
 		threads = calloc(sizeof(*threads), num_threads);

tests/gem_flink.c

@@ -45,7 +45,7 @@ test_flink(int fd)
 	struct drm_gem_open open_struct;
 	int ret;
 
-	printf("Testing flink and open.\n");
+	igt_info("Testing flink and open.\n");
 
 	memset(&create, 0, sizeof(create));
 	create.size = 16 * 1024;
@@ -70,7 +70,7 @@ test_double_flink(int fd)
 	struct drm_gem_flink flink2;
 	int ret;
 
-	printf("Testing repeated flink.\n");
+	igt_info("Testing repeated flink.\n");
 
 	memset(&create, 0, sizeof(create));
 	create.size = 16 * 1024;
@@ -93,7 +93,7 @@ test_bad_flink(int fd)
 	struct drm_gem_flink flink;
 	int ret;
 
-	printf("Testing error return on bad flink ioctl.\n");
+	igt_info("Testing error return on bad flink ioctl.\n");
 
 	flink.handle = 0x10101010;
 	ret = ioctl(fd, DRM_IOCTL_GEM_FLINK, &flink);
@@ -106,7 +106,7 @@ test_bad_open(int fd)
 	struct drm_gem_open open_struct;
 	int ret;
 
-	printf("Testing error return on bad open ioctl.\n");
+	igt_info("Testing error return on bad open ioctl.\n");
 
 	open_struct.name = 0x10101010;
 	ret = ioctl(fd, DRM_IOCTL_GEM_OPEN, &open_struct);
@@ -122,7 +122,7 @@ test_flink_lifetime(int fd)
 	struct drm_gem_open open_struct;
 	int ret, fd2;
 
-	printf("Testing flink lifetime.\n");
+	igt_info("Testing flink lifetime.\n");
 
 	fd2 = drm_open_any();
 

tests/gem_flink_race.c

@@ -197,7 +197,7 @@ static void test_flink_close(void)
 
 	obj_count = get_object_count() - obj_count;
 
-	printf("leaked %i objects\n", obj_count);
+	igt_info("leaked %i objects\n", obj_count);
 
 	close(fake);
 

tests/gem_gtt_hog.c

@@ -187,6 +187,6 @@ igt_simple_main
 		igt_assert(status == 0);
 	}
 	gettimeofday(&end, NULL);
-	printf("Time to execute %lu children:		%7.3fms\n",
+	igt_info("Time to execute %lu children:		%7.3fms\n",
-	       ARRAY_SIZE(children), elapsed(&start, &end) / 1000);
+		 ARRAY_SIZE(children), elapsed(&start, &end) / 1000);
 }

tests/gem_gtt_speed.c

@@ -66,7 +66,7 @@ int main(int argc, char **argv)
 	if (argc > 1)
 		size = atoi(argv[1]);
 	if (size == 0) {
-		fprintf(stderr, "Invalid object size specified\n");
+		igt_warn("Invalid object size specified\n");
 		return 1;
 	}
 
@@ -79,8 +79,8 @@ int main(int argc, char **argv)
 
 	for (tiling = I915_TILING_NONE; tiling <= I915_TILING_Y; tiling++) {
 		if (tiling != I915_TILING_NONE) {
-			printf("\nSetting tiling mode to %s\n",
+			igt_info("\nSetting tiling mode to %s\n",
-			       tiling == I915_TILING_X ? "X" : "Y");
+				 tiling == I915_TILING_X ? "X" : "Y");
 			gem_set_tiling(fd, handle, tiling, 512);
 		}
 
@@ -118,8 +118,8 @@ int main(int argc, char **argv)
 					munmap(base, size);
 				}
 				gettimeofday(&end, NULL);
-				printf("Time to read %dk through a CPU map:		%7.3fµs\n",
+				igt_info("Time to read %dk through a CPU map:		%7.3fµs\n",
-				       size/1024, elapsed(&start, &end, loop));
+					 size/1024, elapsed(&start, &end, loop));
 
 				/* mmap write */
 				gettimeofday(&start, NULL);
@@ -133,8 +133,8 @@ int main(int argc, char **argv)
 					munmap(base, size);
 				}
 				gettimeofday(&end, NULL);
-				printf("Time to write %dk through a CPU map:		%7.3fµs\n",
+				igt_info("Time to write %dk through a CPU map:		%7.3fµs\n",
-				       size/1024, elapsed(&start, &end, loop));
+					 size/1024, elapsed(&start, &end, loop));
 
 				gettimeofday(&start, NULL);
 				for (loop = 0; loop < 1000; loop++) {
@@ -143,8 +143,8 @@ int main(int argc, char **argv)
 					munmap(base, size);
 				}
 				gettimeofday(&end, NULL);
-				printf("Time to clear %dk through a CPU map:		%7.3fµs\n",
+				igt_info("Time to clear %dk through a CPU map:		%7.3fµs\n",
-				       size/1024, elapsed(&start, &end, loop));
+					 size/1024, elapsed(&start, &end, loop));
 
 				gettimeofday(&start, NULL);
 				base = gem_mmap__cpu(fd, handle, size, PROT_READ | PROT_WRITE);
@@ -152,8 +152,8 @@ int main(int argc, char **argv)
 					memset(base, 0, size);
 				munmap(base, size);
 				gettimeofday(&end, NULL);
-				printf("Time to clear %dk through a cached CPU map:	%7.3fµs\n",
+				igt_info("Time to clear %dk through a cached CPU map:	%7.3fµs\n",
-				       size/1024, elapsed(&start, &end, loop));
+					 size/1024, elapsed(&start, &end, loop));
 			}
 
 			/* CPU pwrite */
@@ -161,16 +161,16 @@ int main(int argc, char **argv)
 			for (loop = 0; loop < 1000; loop++)
 				gem_write(fd, handle, 0, buf, size);
 			gettimeofday(&end, NULL);
-			printf("Time to pwrite %dk through the CPU:		%7.3fµs\n",
+			igt_info("Time to pwrite %dk through the CPU:		%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 
 			/* CPU pread */
 			gettimeofday(&start, NULL);
 			for (loop = 0; loop < 1000; loop++)
 				gem_read(fd, handle, 0, buf, size);
 			gettimeofday(&end, NULL);
-			printf("Time to pread %dk through the CPU:		%7.3fµs\n",
+			igt_info("Time to pread %dk through the CPU:		%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 		}
 
 		/* prefault into gtt */
@@ -203,8 +203,8 @@ int main(int argc, char **argv)
 			munmap(base, size);
 		}
 		gettimeofday(&end, NULL);
-		printf("Time to read %dk through a GTT map:		%7.3fµs\n",
+		igt_info("Time to read %dk through a GTT map:		%7.3fµs\n",
-		       size/1024, elapsed(&start, &end, loop));
+			 size/1024, elapsed(&start, &end, loop));
 
 		/* mmap write */
 		gettimeofday(&start, NULL);
@@ -218,8 +218,8 @@ int main(int argc, char **argv)
 			munmap(base, size);
 		}
 		gettimeofday(&end, NULL);
-		printf("Time to write %dk through a GTT map:		%7.3fµs\n",
+		igt_info("Time to write %dk through a GTT map:		%7.3fµs\n",
-		       size/1024, elapsed(&start, &end, loop));
+			 size/1024, elapsed(&start, &end, loop));
 
 		/* mmap clear */
 		gettimeofday(&start, NULL);
@@ -229,8 +229,8 @@ int main(int argc, char **argv)
 			munmap(base, size);
 		}
 		gettimeofday(&end, NULL);
-		printf("Time to clear %dk through a GTT map:		%7.3fµs\n",
+		igt_info("Time to clear %dk through a GTT map:		%7.3fµs\n",
-		       size/1024, elapsed(&start, &end, loop));
+			 size/1024, elapsed(&start, &end, loop));
 
 		gettimeofday(&start, NULL);{
 			uint32_t *base = gem_mmap(fd, handle, size, PROT_READ | PROT_WRITE);
@@ -238,8 +238,8 @@ int main(int argc, char **argv)
 				memset(base, 0, size);
 			munmap(base, size);
 		} gettimeofday(&end, NULL);
-		printf("Time to clear %dk through a cached GTT map:	%7.3fµs\n",
+		igt_info("Time to clear %dk through a cached GTT map:	%7.3fµs\n",
-		       size/1024, elapsed(&start, &end, loop));
+			 size/1024, elapsed(&start, &end, loop));
 
 		/* mmap read */
 		gettimeofday(&start, NULL);
@@ -257,8 +257,8 @@ int main(int argc, char **argv)
 			munmap(base, size);
 		}
 		gettimeofday(&end, NULL);
-		printf("Time to read %dk (again) through a GTT map:	%7.3fµs\n",
+		igt_info("Time to read %dk (again) through a GTT map:	%7.3fµs\n",
-		       size/1024, elapsed(&start, &end, loop));
+			 size/1024, elapsed(&start, &end, loop));
 
 		if (tiling == I915_TILING_NONE) {
 			/* GTT pwrite */
@@ -266,16 +266,16 @@ int main(int argc, char **argv)
 			for (loop = 0; loop < 1000; loop++)
 				gem_write(fd, handle, 0, buf, size);
 			gettimeofday(&end, NULL);
-			printf("Time to pwrite %dk through the GTT:		%7.3fµs\n",
+			igt_info("Time to pwrite %dk through the GTT:		%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 
 			/* GTT pread */
 			gettimeofday(&start, NULL);
 			for (loop = 0; loop < 1000; loop++)
 				gem_read(fd, handle, 0, buf, size);
 			gettimeofday(&end, NULL);
-			printf("Time to pread %dk through the GTT:		%7.3fµs\n",
+			igt_info("Time to pread %dk through the GTT:		%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 
 			/* GTT pwrite, including clflush */
 			gettimeofday(&start, NULL);
@@ -284,8 +284,8 @@ int main(int argc, char **argv)
 				gem_sync(fd, handle);
 			}
 			gettimeofday(&end, NULL);
-			printf("Time to pwrite %dk through the GTT (clflush):	%7.3fµs\n",
+			igt_info("Time to pwrite %dk through the GTT (clflush):	%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 
 			/* GTT pread, including clflush */
 			gettimeofday(&start, NULL);
@@ -294,11 +294,11 @@ int main(int argc, char **argv)
 				gem_read(fd, handle, 0, buf, size);
 			}
 			gettimeofday(&end, NULL);
-			printf("Time to pread %dk through the GTT (clflush):	%7.3fµs\n",
+			igt_info("Time to pread %dk through the GTT (clflush):	%7.3fµs\n",
-			       size/1024, elapsed(&start, &end, loop));
+				 size/1024, elapsed(&start, &end, loop));
 
 			/* partial writes */
-			printf("Now partial writes.\n");
+			igt_info("Now partial writes.\n");
 			size /= 4;
 
 			/* partial GTT pwrite, including clflush */
@@ -308,7 +308,7 @@ int main(int argc, char **argv)
 				gem_sync(fd, handle);
 			}
 			gettimeofday(&end, NULL);
-			printf("Time to pwrite %dk through the GTT (clflush):	%7.3fµs\n",
+			igt_info("Time to pwrite %dk through the GTT (clflush):	%7.3fµs\n",
 			       size/1024, elapsed(&start, &end, loop));
 
 			/* partial GTT pread, including clflush */
@@ -318,7 +318,7 @@ int main(int argc, char **argv)
 				gem_read(fd, handle, 0, buf, size);
 			}
 			gettimeofday(&end, NULL);
-			printf("Time to pread %dk through the GTT (clflush):	%7.3fµs\n",
+			igt_info("Time to pread %dk through the GTT (clflush):	%7.3fµs\n",
 			       size/1024, elapsed(&start, &end, loop));
 
 			size *= 4;

tests/gem_hangcheck_forcewake.c

@@ -77,7 +77,7 @@ igt_simple_main
 	batch = intel_batchbuffer_alloc(bufmgr, devid);
 
 	act_size = 2048;
-	printf("filling ring\n");
+	igt_info("filling ring\n");
 	drm_intel_bo_unreference(bo);
 	bo = drm_intel_bo_alloc_tiled(bufmgr, "tiled bo", act_size, act_size,
 				      4, &tiling_mode, &pitch, 0);
@@ -113,10 +113,10 @@ igt_simple_main
 		}
 	}
 
-	printf("waiting\n");
+	igt_info("waiting\n");
 	sleep(10);
 
-	printf("done waiting, check dmesg\n");
+	igt_info("done waiting, check dmesg\n");
 	drm_intel_bo_unreference(bo);
 
 	intel_batchbuffer_free(batch);

tests/gem_largeobject.c

@@ -60,7 +60,7 @@ test_large_object(int fd)
 	else
 		obj_size = OBJ_SIZE;
 	create.size = obj_size;
-	printf("obj size %i\n", obj_size);
+	igt_info("obj size %i\n", obj_size);
 
 	igt_assert(ioctl(fd, DRM_IOCTL_I915_GEM_CREATE, &create) == 0);
 

tests/gem_linear_blits.c

@@ -203,11 +203,11 @@ static void run_test(int fd, int count)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -218,7 +218,7 @@ static void run_test(int fd, int count)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -229,7 +229,7 @@ static void run_test(int fd, int count)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -270,10 +270,10 @@ int main(int argc, char **argv)
 
 		if (count > intel_get_total_ram_mb() * 9 / 10) {
 			count = intel_get_total_ram_mb() * 9 / 10;
-			printf("not enough RAM to run test, reducing buffer count\n");
+			igt_info("not enough RAM to run test, reducing buffer count\n");
 		}
 
-		printf("Using %d 1MiB buffers\n", count);
+		igt_info("Using %d 1MiB buffers\n", count);
 	}
 
 	igt_subtest("normal")

tests/gem_mmap.c

@@ -73,22 +73,22 @@ igt_main
 		igt_assert(ret == 0);
 		addr = (uint8_t *)(uintptr_t)arg.addr_ptr;
 
-		printf("Testing contents of newly created object.\n");
+		igt_info("Testing contents of newly created object.\n");
 		memset(expected, 0, sizeof(expected));
 		igt_assert(memcmp(addr, expected, sizeof(expected)) == 0);
 
-		printf("Testing coherency of writes and mmap reads.\n");
+		igt_info("Testing coherency of writes and mmap reads.\n");
 		memset(buf, 0, sizeof(buf));
 		memset(buf + 1024, 0x01, 1024);
 		memset(expected + 1024, 0x01, 1024);
 		gem_write(fd, handle, 0, buf, OBJECT_SIZE);
 		igt_assert(memcmp(buf, addr, sizeof(buf)) == 0);
 
-		printf("Testing that mapping stays after close\n");
+		igt_info("Testing that mapping stays after close\n");
 		gem_close(fd, handle);
 		igt_assert(memcmp(buf, addr, sizeof(buf)) == 0);
 
-		printf("Testing unmapping\n");
+		igt_info("Testing unmapping\n");
 		munmap(addr, OBJECT_SIZE);
 	}
 

tests/gem_non_secure_batch.c

@@ -92,7 +92,7 @@ int main(int argc, char **argv)
 		num_rings++;
 
 
-	printf("num rings detected: %i\n", num_rings);
+	igt_info("num rings detected: %i\n", num_rings);
 
 	bufmgr = drm_intel_bufmgr_gem_init(fd, 4096);
 	igt_assert(bufmgr);

tests/gem_partial_pwrite_pread.c

@@ -109,7 +109,7 @@ static void test_partial_reads(void)
 {
 	int i, j;
 
-	printf("checking partial reads\n");
+	igt_info("checking partial reads\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;
@@ -136,7 +136,7 @@ static void test_partial_writes(void)
 	int i, j;
 	uint8_t *gtt_ptr;
 
-	printf("checking partial writes\n");
+	igt_info("checking partial writes\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;
@@ -181,7 +181,7 @@ static void test_partial_read_writes(void)
 	int i, j;
 	uint8_t *gtt_ptr;
 
-	printf("checking partial writes after partial reads\n");
+	igt_info("checking partial writes after partial reads\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;

tests/gem_pread.c

@@ -115,10 +115,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			do_gem_read(fd, dst, src, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("Time to pread %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("Time to pread %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -133,10 +133,10 @@ int main(int argc, char **argv)
 				gettimeofday(&start, NULL);
 				do_gem_read(fd, dst, src, object_size, count);
 				gettimeofday(&end, NULL);
-				printf("Time to %s pread %d bytes x %6d:	%7.3fµs, %s\n",
+				igt_info("Time to %s pread %d bytes x %6d:	%7.3fµs, %s\n",
-						c->name, object_size, count,
+					 c->name, object_size, count,
-						elapsed(&start, &end, count),
+					 elapsed(&start, &end, count),
-						bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+					 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 				fflush(stdout);
 			}
 		}

tests/gem_pread_after_blit.c

@@ -136,8 +136,6 @@ static void do_test(int fd, int cache_level,
 		gem_set_caching(fd, tmp[1]->handle, cache_level);
 	}
 
-	printf("meh");
-
 	do {
 		/* First, do a full-buffer read after blitting */
 		intel_copy_bo(batch, tmp[0], src[0], width*height*4);

tests/gem_pwrite.c

@@ -123,10 +123,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			do_gem_write(fd, dst, src, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("Time to pwrite %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("Time to pwrite %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -141,10 +141,10 @@ int main(int argc, char **argv)
 				gettimeofday(&start, NULL);
 				do_gem_write(fd, dst, src, object_size, count);
 				gettimeofday(&end, NULL);
-				printf("Time to %s pwrite %d bytes x %6d:	%7.3fµs, %s\n",
+				igt_info("Time to %s pwrite %d bytes x %6d:	%7.3fµs, %s\n",
-				       c->name, object_size, count,
+					 c->name, object_size, count,
-				       elapsed(&start, &end, count),
+					 elapsed(&start, &end, count),
-				       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+					 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 				fflush(stdout);
 			}
 		}

tests/gem_pwrite_pread.c

@@ -298,10 +298,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			copy(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("Time to uncached copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("Time to uncached copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -315,10 +315,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			as_gtt_mmap(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("** mmap uncached copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("** mmap uncached copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -337,10 +337,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			copy(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("Time to snooped copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("Time to snooped copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -354,10 +354,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			as_cpu_mmap(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("** mmap snooped copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("** mmap snooped copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -376,10 +376,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			copy(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("Time to display copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("Time to display copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}
@@ -393,10 +393,10 @@ int main(int argc, char **argv)
 			gettimeofday(&start, NULL);
 			as_gtt_mmap(fd, src, dst, tmp, object_size, count);
 			gettimeofday(&end, NULL);
-			printf("** mmap display copy %d bytes x %6d:	%7.3fµs, %s\n",
+			igt_info("** mmap display copy %d bytes x %6d:	%7.3fµs, %s\n",
-			       object_size, count,
+				 object_size, count,
-			       elapsed(&start, &end, count),
+				 elapsed(&start, &end, count),
-			       bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
+				 bytes_per_sec((char *)buf, object_size/elapsed(&start, &end, count)*1e6));
 			fflush(stdout);
 		}
 	}

tests/gem_readwrite.c

@@ -91,7 +91,7 @@ igt_main
 	}
 
 	igt_subtest("new-obj") {
-		printf("Testing contents of newly created object.\n");
+		igt_info("Testing contents of newly created object.\n");
 		ret = do_read(fd, handle, buf, 0, OBJECT_SIZE);
 		igt_assert(ret == 0);
 		memset(&expected, 0, sizeof(expected));
@@ -99,13 +99,13 @@ igt_main
 	}
 
 	igt_subtest("beyond-EOB") {
-		printf("Testing read beyond end of buffer.\n");
+		igt_info("Testing read beyond end of buffer.\n");
 		ret = do_read(fd, handle, buf, OBJECT_SIZE / 2, OBJECT_SIZE);
 		igt_assert(ret == -1 && errno == EINVAL);
 	}
 
 	igt_subtest("read-write") {
-		printf("Testing full write of buffer\n");
+		igt_info("Testing full write of buffer\n");
 		memset(buf, 0, sizeof(buf));
 		memset(buf + 1024, 0x01, 1024);
 		memset(expected + 1024, 0x01, 1024);
@@ -115,7 +115,7 @@ igt_main
 		igt_assert(ret == 0);
 		igt_assert(memcmp(buf, expected, sizeof(buf)) == 0);
 
-		printf("Testing partial write of buffer\n");
+		igt_info("Testing partial write of buffer\n");
 		memset(buf + 4096, 0x02, 1024);
 		memset(expected + 4096, 0x02, 1024);
 		ret = do_write(fd, handle, buf + 4096, 4096, 1024);
@@ -124,20 +124,20 @@ igt_main
 		igt_assert(ret == 0);
 		igt_assert(memcmp(buf, expected, sizeof(buf)) == 0);
 
-		printf("Testing partial read of buffer\n");
+		igt_info("Testing partial read of buffer\n");
 		ret = do_read(fd, handle, buf, 512, 1024);
 		igt_assert(ret == 0);
 		igt_assert(memcmp(buf, expected + 512, 1024) == 0);
 	}
 
 	igt_subtest("read-bad-handle") {
-		printf("Testing read of bad buffer handle\n");
+		igt_info("Testing read of bad buffer handle\n");
 		ret = do_read(fd, 1234, buf, 0, 1024);
 		igt_assert(ret == -1 && errno == ENOENT);
 	}
 
 	igt_subtest("write-bad-handle") {
-		printf("Testing write of bad buffer handle\n");
+		igt_info("Testing write of bad buffer handle\n");
 		ret = do_write(fd, 1234, buf, 0, 1024);
 		igt_assert(ret == -1 && errno == ENOENT);
 	}

tests/gem_render_linear_blits.c

@@ -120,7 +120,7 @@ int main(int argc, char **argv)
 
 	if (count > intel_get_total_ram_mb() * 9 / 10) {
 		count = intel_get_total_ram_mb() * 9 / 10;
-		printf("not enough RAM to run test, reducing buffer count\n");
+		igt_info("not enough RAM to run test, reducing buffer count\n");
 	}
 
 	bo = malloc(sizeof(*bo)*count);
@@ -134,11 +134,11 @@ int main(int argc, char **argv)
 		gem_write(fd, bo[i]->handle, 0, linear, sizeof(linear));
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(fd, bo[i]->handle, start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		struct igt_buf src, dst;
 
@@ -161,7 +161,7 @@ int main(int argc, char **argv)
 	if (igt_run_in_simulation())
 		return 0;
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		struct igt_buf src, dst;
 
@@ -181,7 +181,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(fd, bo[i]->handle, start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		struct igt_buf src, dst;
 		int s = random() % count;

tests/gem_render_tiled_blits.c

@@ -142,15 +142,15 @@ int main(int argc, char **argv)
 
 	if (count > intel_get_total_ram_mb() * 9 / 10) {
 		count = intel_get_total_ram_mb() * 9 / 10;
-		printf("not enough RAM to run test, reducing buffer count\n");
+		igt_info("not enough RAM to run test, reducing buffer count\n");
 	}
 
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	linear = drm_intel_bo_alloc(bufmgr, "linear", WIDTH*HEIGHT*4, 0);
 	if (snoop) {
 		gem_set_caching(fd, linear->handle, 1);
-		printf("Using a snoop linear buffer for comparisons\n");
+		igt_info("Using a snoop linear buffer for comparisons\n");
 	}
 
 	buf = malloc(sizeof(*buf)*count);
@@ -177,11 +177,11 @@ int main(int argc, char **argv)
 		drm_intel_gem_bo_unmap_gtt(buf[i].bo);
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(batch, &buf[i], start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -192,7 +192,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(batch, &buf[i], start_val[i]);
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -203,7 +203,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(batch, &buf[i], start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;

tests/gem_reset_stats.c

@@ -303,12 +303,10 @@ static int inject_hang_ring(int fd, int ctx, int ring, bool ignore_ban_error)
 
 	buf[roff + cmd_len] = MI_BATCH_BUFFER_END;
 
-#ifdef VERBOSE
+	igt_debug("loop injected at 0x%lx (off 0x%x, bo_start 0x%lx, bo_end 0x%lx)\n",
-	printf("loop injected at 0x%lx (off 0x%x, bo_start 0x%lx, bo_end 0x%lx)\n",
+		  (long unsigned int)((roff << 2) + gtt_off),
-	       (long unsigned int)((roff << 2) + gtt_off),
+		  roff << 2, (long unsigned int)gtt_off,
-	       roff << 2, (long unsigned int)gtt_off,
+		  (long unsigned int)(gtt_off + BUFSIZE - 1));
-	       (long unsigned int)(gtt_off + BUFSIZE - 1));
-#endif
 	gem_write(fd, exec.handle, 0, buf, BUFSIZE);
 
 	exec.relocation_count = 0;
@@ -365,14 +363,14 @@ static int _assert_reset_status(int fd, int ctx, int status)
 
 	rs = gem_reset_status(fd, ctx);
 	if (rs < 0) {
-		printf("reset status for %d ctx %d returned %d\n",
+		igt_info("reset status for %d ctx %d returned %d\n",
-		       fd, ctx, rs);
+			 fd, ctx, rs);
 		return rs;
 	}
 
 	if (rs != status) {
-		printf("%d:%d reset status %d differs from assumed %d\n",
+		igt_info("%d:%d reset status %d differs from assumed %d\n",
-		       fd, ctx, rs, status);
+			 fd, ctx, rs, status);
 
 		return 1;
 	}
@@ -568,7 +566,7 @@ static void test_ban(void)
                 gem_close(fd_bad, h3);
                 gem_close(fd_bad, h4);
 
-                printf("retrying for ban (%d)\n", retry);
+                igt_info("retrying for ban (%d)\n", retry);
         }
 
 	igt_assert(h4 == -EIO);
@@ -660,7 +658,7 @@ static void test_ban_ctx(void)
                 gem_close(fd, h3);
                 gem_close(fd, h4);
 
-                printf("retrying for ban (%d)\n", retry);
+                igt_info("retrying for ban (%d)\n", retry);
         }
 
 	igt_assert(h4 == -EIO);

tests/gem_ringfill.c

@@ -95,8 +95,8 @@ static int check_bo(struct bo *b)
 			int x = i % width;
 			int y = i / width;
 
-			printf("%s: copy #%d at %d,%d failed: read 0x%08x\n",
+			igt_info("%s: copy #%d at %d,%d failed: read 0x%08x\n",
-			       b->ring, i, x, y, map[i]);
+				 b->ring, i, x, y, map[i]);
 		}
 	}
 	drm_intel_bo_unmap(b->dst);
@@ -165,7 +165,7 @@ static int check_ring(drm_intel_bufmgr *bufmgr,
 	}
 
 	/* verify */
-	printf("verifying\n");
+	igt_info("verifying\n");
 	i = check_bo(&bo);
 	destroy_bo(&bo);
 

tests/gem_set_tiling_vs_blt.c

@@ -82,7 +82,7 @@ static void do_test(uint32_t tiling, unsigned stride,
 	uint32_t blt_stride, blt_bits;
 	bool tiling_changed = false;
 
-	printf("filling ring .. ");
+	igt_info("filling ring .. ");
 	busy_bo = drm_intel_bo_alloc(bufmgr, "busy bo bo", 16*1024*1024, 4096);
 
 	for (i = 0; i < 250; i++) {
@@ -110,7 +110,7 @@ static void do_test(uint32_t tiling, unsigned stride,
 	}
 	intel_batchbuffer_flush(batch);
 
-	printf("playing tricks .. ");
+	igt_info("playing tricks .. ");
 	/* first allocate the target so it gets out of the way of playing funky
 	 * tricks */
 	target_bo = drm_intel_bo_alloc(bufmgr, "target bo", TEST_SIZE, 4096);
@@ -202,7 +202,7 @@ static void do_test(uint32_t tiling, unsigned stride,
 	/* Now try to trick the kernel the kernel into changing up the fencing
 	 * too early. */
 
-	printf("checking .. ");
+	igt_info("checking .. ");
 	memset(data, 0, TEST_SIZE);
 	drm_intel_bo_get_subdata(target_bo, 0, TEST_SIZE, data);
 	for (i = 0; i < TEST_SIZE/4; i++)
@@ -221,7 +221,7 @@ static void do_test(uint32_t tiling, unsigned stride,
 	drm_intel_bo_unreference(test_bo);
 	drm_intel_bo_unreference(target_bo);
 	drm_intel_bo_unreference(busy_bo);
-	printf("done\n");
+	igt_info("done\n");
 }
 
 int fd;
@@ -246,7 +246,6 @@ igt_main
 	}
 
 	igt_subtest("untiled-to-tiled") {
-		printf("testing untiled->tiled transisition:\n");
 		tiling = I915_TILING_NONE;
 		tiling_after = I915_TILING_X;
 		do_test(tiling, TEST_STRIDE, tiling_after, TEST_STRIDE);
@@ -255,7 +254,6 @@ igt_main
 	}
 
 	igt_subtest("tiled-to-untiled") {
-		printf("testing tiled->untiled transisition:\n");
 		tiling = I915_TILING_X;
 		tiling_after = I915_TILING_NONE;
 		do_test(tiling, TEST_STRIDE, tiling_after, TEST_STRIDE);
@@ -264,7 +262,6 @@ igt_main
 	}
 
 	igt_subtest("tiled-to-tiled") {
-		printf("testing tiled->tiled transisition:\n");
 		tiling = I915_TILING_X;
 		tiling_after = I915_TILING_X;
 		do_test(tiling, TEST_STRIDE/2, tiling_after, TEST_STRIDE);

tests/gem_set_tiling_vs_gtt.c

@@ -77,7 +77,7 @@ igt_simple_main
 
 	gem_set_tiling(fd, handle, I915_TILING_X, TEST_STRIDE);
 
-	printf("testing untiled->tiled\n");
+	igt_info("testing untiled->tiled\n");
 	tiling_changed = false;
 	gem_set_domain(fd, handle, I915_GEM_DOMAIN_GTT, 0);
 	/* Too lazy to check for the correct tiling, and impossible anyway on
@@ -93,7 +93,7 @@ igt_simple_main
 
 	gem_set_tiling(fd, handle, I915_TILING_X, TEST_STRIDE*2);
 
-	printf("testing tiled->tiled\n");
+	igt_info("testing tiled->tiled\n");
 	gem_set_domain(fd, handle, I915_GEM_DOMAIN_GTT, 0);
 	for (i = 0; i < OBJECT_SIZE/4; i++) {
 		int tile_row = i / (TEST_STRIDE * tile_height / 4);
@@ -120,7 +120,7 @@ igt_simple_main
 		ptr[i] = data[i] = i;
 
 	gem_set_tiling(fd, handle, I915_TILING_NONE, 0);
-	printf("testing tiled->untiled\n");
+	igt_info("testing tiled->untiled\n");
 	tiling_changed = false;
 	gem_set_domain(fd, handle, I915_GEM_DOMAIN_GTT, 0);
 	/* Too lazy to check for the correct tiling, and impossible anyway on

tests/gem_set_tiling_vs_pwrite.c

@@ -71,7 +71,7 @@ igt_simple_main
 	gem_set_domain(fd, handle, I915_GEM_DOMAIN_GTT, I915_GEM_DOMAIN_GTT);
 	*ptr = 0xdeadbeef;
 
-	printf("testing pwrite on tiled buffer\n");
+	igt_info("testing pwrite on tiled buffer\n");
 	gem_write(fd, handle, 0, data, OBJECT_SIZE);
 	memset(data, 0, OBJECT_SIZE);
 	gem_read(fd, handle, 0, data, OBJECT_SIZE);
@@ -84,7 +84,7 @@ igt_simple_main
 
 	gem_set_tiling(fd, handle, I915_TILING_NONE, 0);
 
-	printf("testing pwrite on untiled, but still fenced buffer\n");
+	igt_info("testing pwrite on untiled, but still fenced buffer\n");
 	gem_write(fd, handle, 0, data, OBJECT_SIZE);
 	memset(data, 0, OBJECT_SIZE);
 	gem_read(fd, handle, 0, data, OBJECT_SIZE);

tests/gem_storedw_batches_loop.c

@@ -56,7 +56,7 @@ store_dword_loop(int divider, unsigned flags)
 	uint32_t *buf;
 	drm_intel_bo *cmd_bo;
 
-	printf("running storedw loop with stall every %i batch\n", divider);
+	igt_info("running storedw loop with stall every %i batch\n", divider);
 
 	cmd = MI_STORE_DWORD_IMM;
 	if (!has_ppgtt)
@@ -126,7 +126,7 @@ cont:
 		val++;
 	}
 
-	printf("completed %d writes successfully\n", i);
+	igt_info("completed %d writes successfully\n", i);
 }
 
 int fd;

tests/gem_storedw_loop_blt.c

@@ -84,7 +84,7 @@ store_dword_loop(int devid, int divider)
 	int i, val = 0;
 	uint32_t *buf;
 
-	printf("running storedw loop on render with stall every %i batch\n", divider);
+	igt_info("running storedw loop on render with stall every %i batch\n", divider);
 
 	for (i = 0; i < SLOW_QUICK(0x100000, 0x10); i++) {
 		emit_store_dword_imm(devid, target_buffer, val);
@@ -109,7 +109,7 @@ cont:
 	drm_intel_bo_map(target_buffer, 0);
 	buf = target_buffer->virtual;
 
-	printf("completed %d writes successfully, current value: 0x%08x\n", i,
+	igt_info("completed %d writes successfully, current value: 0x%08x\n", i,
 			buf[0]);
 	drm_intel_bo_unmap(target_buffer);
 }

tests/gem_storedw_loop_bsd.c

@@ -84,7 +84,7 @@ store_dword_loop(int devid, int divider)
 	int i, val = 0;
 	uint32_t *buf;
 
-	printf("running storedw loop on render with stall every %i batch\n", divider);
+	igt_info("running storedw loop on render with stall every %i batch\n", divider);
 
 	for (i = 0; i < SLOW_QUICK(0x100000, 0x10); i++) {
 		emit_store_dword_imm(devid, target_buffer, val);
@@ -109,7 +109,7 @@ cont:
 	drm_intel_bo_map(target_buffer, 0);
 	buf = target_buffer->virtual;
 
-	printf("completed %d writes successfully, current value: 0x%08x\n", i,
+	igt_info("completed %d writes successfully, current value: 0x%08x\n", i,
 			buf[0]);
 	drm_intel_bo_unmap(target_buffer);
 }

tests/gem_storedw_loop_render.c

@@ -84,7 +84,7 @@ store_dword_loop(int devid, int divider)
 	int i, val = 0;
 	uint32_t *buf;
 
-	printf("running storedw loop on render with stall every %i batch\n", divider);
+	igt_info("running storedw loop on render with stall every %i batch\n", divider);
 
 	for (i = 0; i < SLOW_QUICK(0x100000, 0x10); i++) {
 		emit_store_dword_imm(devid, target_buffer, val);
@@ -109,7 +109,7 @@ cont:
 	drm_intel_bo_map(target_buffer, 0);
 	buf = target_buffer->virtual;
 
-	printf("completed %d writes successfully, current value: 0x%08x\n", i,
+	igt_info("completed %d writes successfully, current value: 0x%08x\n", i,
 			buf[0]);
 	drm_intel_bo_unmap(target_buffer);
 }

tests/gem_storedw_loop_vebox.c

@@ -57,7 +57,7 @@ store_dword_loop(int divider)
 	int cmd, i, val = 0;
 	uint32_t *buf;
 
-	printf("running storedw loop on blt with stall every %i batch\n", divider);
+	igt_info("running storedw loop on blt with stall every %i batch\n", divider);
 
 	cmd = MI_STORE_DWORD_IMM;
 
@@ -96,7 +96,7 @@ cont:
 	drm_intel_bo_map(target_buffer, 0);
 	buf = target_buffer->virtual;
 
-	printf("completed %d writes successfully, current value: 0x%08x\n", i,
+	igt_info("completed %d writes successfully, current value: 0x%08x\n", i,
 			buf[0]);
 	drm_intel_bo_unmap(target_buffer);
 }

tests/gem_tiled_blits.c

@@ -133,11 +133,11 @@ static void run_test(int count)
 		bo_start_val[i] = start;
 		start += 1024 * 1024 / 4;
 	}
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(bo[i], bo_start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i+1) % count;
@@ -159,7 +159,7 @@ static void run_test(int count)
 		return;
 	}
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i+1) % count;
 		int dst = i % count;
@@ -173,7 +173,7 @@ static void run_test(int count)
 	for (i = 0; i < count; i++)
 		check_bo(bo[i], bo_start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -218,10 +218,10 @@ int main(int argc, char **argv)
 
 		if (count > intel_get_total_ram_mb() * 9 / 10) {
 			count = intel_get_total_ram_mb() * 9 / 10;
-			printf("not enough RAM to run test, reducing buffer count\n");
+			igt_info("not enough RAM to run test, reducing buffer count\n");
 		}
 
-		printf("Using %d 1MiB buffers\n", count);
+		igt_info("Using %d 1MiB buffers\n", count);
 
 		bufmgr = drm_intel_bufmgr_gem_init(fd, 4096);
 		drm_intel_bufmgr_gem_enable_reuse(bufmgr);

tests/gem_tiled_fence_blits.c

@@ -117,10 +117,10 @@ igt_simple_main
 	count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
 	if (count > intel_get_total_ram_mb() * 9 / 10) {
 		count = intel_get_total_ram_mb() * 9 / 10;
-		printf("not enough RAM to run test, reducing buffer count\n");
+		igt_info("not enough RAM to run test, reducing buffer count\n");
 	}
 	count |= 1;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	bufmgr = drm_intel_bufmgr_gem_init(fd, 4096);
 	drm_intel_bufmgr_gem_enable_reuse(bufmgr);
@@ -131,7 +131,7 @@ igt_simple_main
 		bo_start_val[i] = start;
 
 		/*
-		printf("Creating bo %d\n", i);
+		igt_info("Creating bo %d\n", i);
 		check_bo(bo[i], bo_start_val[i]);
 		*/
 
@@ -156,13 +156,13 @@ igt_simple_main
 
 		/*
 		check_bo(bo[dst], bo_start_val[dst]);
-		printf("%d: copy bo %d to %d\n", i, src, dst);
+		igt_info("%d: copy bo %d to %d\n", i, src, dst);
 		*/
 	}
 
 	for (i = 0; i < count; i++) {
 		/*
-		printf("check %d\n", i);
+		igt_info("check %d\n", i);
 		*/
 		check_bo(fd, bo[i], bo_start_val[i]);
 

tests/gem_tiled_partial_pwrite_pread.c

@@ -131,7 +131,6 @@ static void test_partial_reads(void)
 {
 	int i, j;
 
-	printf("checking partial reads\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;
@@ -156,7 +155,6 @@ static void test_partial_writes(void)
 {
 	int i, j;
 
-	printf("checking partial writes\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;
@@ -199,7 +197,6 @@ static void test_partial_read_writes(void)
 {
 	int i, j;
 
-	printf("checking partial writes after partial reads\n");
 	for (i = 0; i < ROUNDS; i++) {
 		int start, len;
 		int val = i % 256;

tests/gem_tiled_pread.c

@@ -120,7 +120,7 @@ calculate_expected(int offset)
 	int tile_y = tile_off / tile_width;
 	int tile_x = (tile_off % tile_width) / 4;
 
-	/* printf("%3d, %3d, %3d,%3d\n", base_x, base_y, tile_x, tile_y); */
+	igt_debug("%3d, %3d, %3d,%3d\n", base_x, base_y, tile_x, tile_y);
 	return (base_y + tile_y) * WIDTH + base_x + tile_x;
 }
 

tests/gem_unfence_active_buffers.c

@@ -82,7 +82,7 @@ igt_simple_main
 	devid = intel_get_drm_devid(fd);
 	batch = intel_batchbuffer_alloc(bufmgr, devid);
 
-	printf("filling ring\n");
+	igt_info("filling ring\n");
 	busy_bo = drm_intel_bo_alloc(bufmgr, "busy bo bo", 16*1024*1024, 4096);
 
 	for (i = 0; i < 250; i++) {
@@ -111,7 +111,7 @@ igt_simple_main
 	intel_batchbuffer_flush(batch);
 
 	num_fences = gem_available_fences(fd);
-	printf("creating havoc on %i fences\n", num_fences);
+	igt_info("creating havoc on %i fences\n", num_fences);
 
 	for (i = 0; i < num_fences*2; i++) {
 		test_bo = drm_intel_bo_alloc(bufmgr, "test_bo",
@@ -135,7 +135,7 @@ igt_simple_main
 		BLIT_RELOC_UDW(devid);
 		ADVANCE_BATCH();
 		intel_batchbuffer_flush(batch);
-		printf("test bo offset: %#lx\n", test_bo->offset);
+		igt_info("test bo offset: %#lx\n", test_bo->offset);
 
 		drm_intel_bo_unreference(test_bo);
 	}

tests/gem_userptr_blits.c

@@ -767,7 +767,7 @@ static int test_coherency(int fd, int count)
 	uint32_t start = 0;
 	int i, ret;
 
-	printf("Using 2x%d 1MiB buffers\n", count);
+	igt_info("Using 2x%d 1MiB buffers\n", count);
 
 	ret = posix_memalign((void **)&memory, PAGE_SIZE, count*sizeof(linear));
 	if (ret != 0 || memory == NULL) {
@@ -793,13 +793,13 @@ static int test_coherency(int fd, int count)
 		start += WIDTH*HEIGHT;
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++) {
 		check_gpu(fd, gpu[i], gpu_val[i]);
 		check_cpu(memory+i*WIDTH*HEIGHT, cpu_val[i]);
 	}
 
-	printf("Cyclic blits cpu->gpu, forward...\n");
+	igt_info("Cyclic blits cpu->gpu, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -810,7 +810,7 @@ static int test_coherency(int fd, int count)
 	for (i = 0; i < count; i++)
 		check_gpu(fd, gpu[i], gpu_val[i]);
 
-	printf("Cyclic blits gpu->cpu, backward...\n");
+	igt_info("Cyclic blits gpu->cpu, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -823,7 +823,7 @@ static int test_coherency(int fd, int count)
 		check_cpu(memory+i*WIDTH*HEIGHT, cpu_val[i]);
 	}
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -1068,7 +1068,7 @@ int main(int argc, char **argv)
 		size = sizeof(linear);
 
 		aperture_size = gem_aperture_size(fd);
-		printf("Aperture size is %lu MiB\n", (long)(aperture_size / (1024*1024)));
+		igt_info("Aperture size is %lu MiB\n", (long)(aperture_size / (1024*1024)));
 
 		if (argc > 1)
 			count = atoi(argv[1]);
@@ -1076,11 +1076,11 @@ int main(int argc, char **argv)
 			count = 2 * aperture_size / (1024*1024) / 3;
 
 		total_ram = intel_get_total_ram_mb();
-		printf("Total RAM is %u MiB\n", total_ram);
+		igt_info("Total RAM is %u MiB\n", total_ram);
 
 		if (count > total_ram * 3 / 4) {
 			count = intel_get_total_ram_mb() * 3 / 4;
-			printf("Not enough RAM to run test, reducing buffer count.\n");
+			igt_info("Not enough RAM to run test, reducing buffer count.\n");
 		}
 	}
 
@@ -1096,7 +1096,7 @@ int main(int argc, char **argv)
 	igt_subtest("forbidden-operations")
 		test_forbidden_ops(fd);
 
-	printf("Testing unsynchronized mappings...\n");
+	igt_info("Testing unsynchronized mappings...\n");
 	gem_userptr_test_unsynchronized();
 
 	igt_subtest("create-destroy-unsync")
@@ -1167,7 +1167,7 @@ int main(int argc, char **argv)
 
 	igt_stop_signal_helper();
 
-	printf("Testing synchronized mappings...\n");
+	igt_info("Testing synchronized mappings...\n");
 
 	igt_fixture {
 		size = sizeof(linear);

tests/gem_wait_render_timeout.c

@@ -183,7 +183,7 @@ igt_simple_main
 
 	igt_assert_cmpint(iter, <, 1000000);
 
-	printf("%d iters is enough work\n", iter);
+	igt_info("%d iters is enough work\n", iter);
 	gem_quiescent_gpu(fd);
 	if (do_signals)
 		igt_fork_signal_helper();
@@ -201,9 +201,9 @@ igt_simple_main
 	igt_assert(gem_bo_busy(fd, dst2->handle) == false);
 	igt_assert_cmpint(timeout, !=, 0);
 	if (timeout ==  (ENOUGH_WORK_IN_SECONDS * NSEC_PER_SEC))
-		printf("Buffer was already done!\n");
+		igt_info("Buffer was already done!\n");
 	else {
-		printf("Finished with %lu time remaining\n", timeout);
+		igt_info("Finished with %lu time remaining\n", timeout);
 	}
 
 	/* check that polling with timeout=0 works. */

tests/gen3_mixed_blits.c

@@ -479,7 +479,7 @@ int main(int argc, char **argv)
 		count = atoi(argv[1]);
 	if (count == 0)
 		count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	handle = malloc(sizeof(uint32_t)*count*3);
 	tiling = handle + count;
@@ -491,12 +491,12 @@ int main(int argc, char **argv)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation..."); fflush(stdout);
+	igt_info("Verifying initialisation..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, forward..."); fflush(stdout);
+	igt_info("Cyclic blits, forward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -504,12 +504,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, backward..."); fflush(stdout);
+	igt_info("Cyclic blits, backward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -517,12 +517,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Random blits..."); fflush(stdout);
+	igt_info("Random blits..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -533,10 +533,10 @@ int main(int argc, char **argv)
 			copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
 	return 0;
 }

tests/gen3_render_linear_blits.c

@@ -347,7 +347,7 @@ int main(int argc, char **argv)
 		count = atoi(argv[1]);
 	if (count == 0)
 		count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	handle = malloc(sizeof(uint32_t)*count*2);
 	start_val = handle + count;
@@ -358,11 +358,11 @@ int main(int argc, char **argv)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -373,7 +373,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -384,7 +384,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;

tests/gen3_render_mixed_blits.c

@@ -367,7 +367,7 @@ int main(int argc, char **argv)
 		count = atoi(argv[1]);
 	if (count == 0)
 		count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	handle = malloc(sizeof(uint32_t)*count*3);
 	tiling = handle + count;
@@ -379,12 +379,12 @@ int main(int argc, char **argv)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation..."); fflush(stdout);
+	igt_info("Verifying initialisation..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, forward..."); fflush(stdout);
+	igt_info("Cyclic blits, forward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -392,12 +392,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, backward..."); fflush(stdout);
+	igt_info("Cyclic blits, backward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -405,12 +405,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Random blits..."); fflush(stdout);
+	igt_info("Random blits..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -421,10 +421,10 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], tiling[dst], handle[src], tiling[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
 	return 0;
 }

tests/gen3_render_tiledx_blits.c

@@ -354,7 +354,7 @@ int main(int argc, char **argv)
 		count = atoi(argv[1]);
 	if (count == 0)
 		count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	handle = malloc(sizeof(uint32_t)*count*2);
 	start_val = handle + count;
@@ -365,11 +365,11 @@ int main(int argc, char **argv)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation...\n");
+	igt_info("Verifying initialisation...\n");
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, forward...\n");
+	igt_info("Cyclic blits, forward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -380,7 +380,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Cyclic blits, backward...\n");
+	igt_info("Cyclic blits, backward...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -391,7 +391,7 @@ int main(int argc, char **argv)
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
 
-	printf("Random blits...\n");
+	igt_info("Random blits...\n");
 	for (i = 0; i < count * 4; i++) {
 		int src = random() % count;
 		int dst = random() % count;

tests/gen3_render_tiledy_blits.c

@@ -354,7 +354,7 @@ int main(int argc, char **argv)
 		count = atoi(argv[1]);
 	if (count == 0)
 		count = 3 * gem_aperture_size(fd) / (1024*1024) / 2;
-	printf("Using %d 1MiB buffers\n", count);
+	igt_info("Using %d 1MiB buffers\n", count);
 
 	handle = malloc(sizeof(uint32_t)*count*2);
 	start_val = handle + count;
@@ -365,12 +365,12 @@ int main(int argc, char **argv)
 		start += 1024 * 1024 / 4;
 	}
 
-	printf("Verifying initialisation..."); fflush(stdout);
+	igt_info("Verifying initialisation..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, forward..."); fflush(stdout);
+	igt_info("Cyclic blits, forward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = i % count;
 		int dst = (i + 1) % count;
@@ -378,12 +378,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], handle[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Cyclic blits, backward..."); fflush(stdout);
+	igt_info("Cyclic blits, backward..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = (i + 1) % count;
 		int dst = i % count;
@@ -391,12 +391,12 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], handle[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
-	printf("Random blits..."); fflush(stdout);
+	igt_info("Random blits..."); fflush(stdout);
 	for (i = 0; i < count * 32; i++) {
 		int src = random() % count;
 		int dst = random() % count;
@@ -407,10 +407,10 @@ int main(int argc, char **argv)
 		copy(fd, handle[dst], handle[src]);
 		start_val[dst] = start_val[src];
 	}
-	printf("verifying..."); fflush(stdout);
+	igt_info("verifying..."); fflush(stdout);
 	for (i = 0; i < count; i++)
 		check_bo(fd, handle[i], start_val[i]);
-	printf("done\n");
+	igt_info("done\n");
 
 	return 0;
 }

tests/gen7_forcewake_mt.c

@@ -193,7 +193,7 @@ igt_simple_main
 
 		p = gem_mmap(t[0].fd, exec[0].handle, 4096, PROT_READ);
 
-		printf("[%d]={ %08x %08x }\n", i, p[0], p[1]);
+		igt_info("[%d]={ %08x %08x }\n", i, p[0], p[1]);
 		igt_assert(p[0] & 2);
 		igt_assert((p[1] & 2) == 0);
 

tests/kms_cursor_crc.c

@@ -105,7 +105,7 @@ static void do_single_test(test_data_t *test_data, int x, int y)
 	igt_plane_t *cursor;
 	cairo_t *cr = igt_get_cairo_ctx(data->drm_fd, &data->primary_fb);
 
-	printf("."); fflush(stdout);
+	igt_info("."); fflush(stdout);
 
 	/* Hardware test */
 	igt_paint_test_pattern(cr, test_data->screenw, test_data->screenh);
@@ -258,8 +258,8 @@ static bool prepare_crtc(test_data_t *test_data, igt_output_t *output,
 	test_data->pipe_crc = igt_pipe_crc_new(test_data->pipe,
 					       INTEL_PIPE_CRC_SOURCE_AUTO);
 	if (!test_data->pipe_crc) {
-		printf("auto crc not supported on this connector with pipe %i\n",
+		igt_info("auto crc not supported on this connector with pipe %i\n",
-		       test_data->pipe);
+			 test_data->pipe);
 		return false;
 	}
 
@@ -321,15 +321,15 @@ static void run_test(data_t *data, void (*testfunc)(test_data_t *), int cursor_w
 
 			valid_tests++;
 
-			fprintf(stdout, "Beginning %s on pipe %c, connector %s\n",
+			igt_info("Beginning %s on pipe %c, connector %s\n",
-				igt_subtest_name(), pipe_name(test_data.pipe),
+				 igt_subtest_name(), pipe_name(test_data.pipe),
-				igt_output_name(output));
+				 igt_output_name(output));
 
 			testfunc(&test_data);
 
-			fprintf(stdout, "\n%s on pipe %c, connector %s: PASSED\n\n",
+			igt_info("\n%s on pipe %c, connector %s: PASSED\n\n",
-				igt_subtest_name(), pipe_name(test_data.pipe),
+				 igt_subtest_name(), pipe_name(test_data.pipe),
-				igt_output_name(output));
+				 igt_output_name(output));
 
 			/* cleanup what prepare_crtc() has done */
 			cleanup_crtc(&test_data, output);

tests/kms_fbc_crc.c

@@ -325,7 +325,7 @@ static bool prepare_test(data_t *data, enum test_mode test_mode)
 	usleep(300000);
 
 	if (!fbc_enabled(data)) {
-		printf("FBC not enabled\n");
+		igt_info("FBC not enabled\n");
 
 		igt_plane_set_fb(data->primary, NULL);
 		igt_output_set_pipe(output, PIPE_ANY);
@@ -342,8 +342,8 @@ static bool prepare_test(data_t *data, enum test_mode test_mode)
 	pipe_crc = igt_pipe_crc_new(data->pipe,
 				    INTEL_PIPE_CRC_SOURCE_AUTO);
 	if (!pipe_crc) {
-		printf("auto crc not supported on this connector with crtc %i\n",
+		igt_info("auto crc not supported on this connector with crtc %i\n",
-		       data->pipe);
+			 data->pipe);
 
 		igt_plane_set_fb(data->primary, NULL);
 		igt_output_set_pipe(output, PIPE_ANY);
@@ -457,14 +457,14 @@ static void run_test(data_t *data, enum test_mode mode)
 			if (!prepare_crtc(data))
 				continue;
 
-			printf("Beginning %s on pipe %c, connector %s\n",
+			igt_info("Beginning %s on pipe %c, connector %s\n",
-			       igt_subtest_name(), pipe_name(data->pipe),
+				 igt_subtest_name(), pipe_name(data->pipe),
-			       igt_output_name(data->output));
+				 igt_output_name(data->output));
 
 			if (!prepare_test(data, mode)) {
-				printf("%s on pipe %c, connector %s: SKIPPED\n",
+				igt_info("%s on pipe %c, connector %s: SKIPPED\n",
-				       igt_subtest_name(), pipe_name(data->pipe),
+					 igt_subtest_name(), pipe_name(data->pipe),
-				       igt_output_name(data->output));
+					 igt_output_name(data->output));
 				continue;
 			}
 
@@ -472,9 +472,9 @@ static void run_test(data_t *data, enum test_mode mode)
 
 			test_crc(data, mode);
 
-			printf("%s on pipe %c, connector %s: PASSED\n",
+			igt_info("%s on pipe %c, connector %s: PASSED\n",
-			       igt_subtest_name(), pipe_name(data->pipe),
+				 igt_subtest_name(), pipe_name(data->pipe),
-			       igt_output_name(data->output));
+				 igt_output_name(data->output));
 
 			finish_crtc(data, mode);
 		}

tests/kms_pipe_crc_basic.c

@@ -70,9 +70,9 @@ static void test_read_crc(data_t *data, int pipe, unsigned flags)
 
 		igt_output_set_pipe(output, pipe);
 
-		fprintf(stdout, "%s: Testing connector %s using pipe %c\n",
+		igt_info("%s: Testing connector %s using pipe %c\n",
-			igt_subtest_name(), igt_output_name(output),
+			 igt_subtest_name(), igt_output_name(output),
-			pipe_name(pipe));
+			 pipe_name(pipe));
 
 		mode = igt_output_get_mode(output);
 		igt_create_color_fb(data->drm_fd,

tests/kms_plane.c

@@ -140,8 +140,8 @@ test_plane_position_with_output(data_t *data,
 	drmModeModeInfo *mode;
 	igt_crc_t crc;
 
-	fprintf(stdout, "Testing connector %s using pipe %c plane %d\n",
+	igt_info("Testing connector %s using pipe %c plane %d\n",
-		igt_output_name(output), pipe_name(pipe), plane);
+		 igt_output_name(output), pipe_name(pipe), plane);
 
 	test_position_init(&test, output, pipe);
 

tests/kms_render.c

@@ -120,8 +120,8 @@ static int test_format(const char *test_name,
 		       kmstest_connector_type_str(cconf->connector->connector_type));
 	igt_assert(ret > 0);
 
-	printf("Beginning test %s with %s on %s\n",
+	igt_info("Beginning test %s with %s on %s\n",
-		test_name, mode_format_str, cconf_str);
+		 test_name, mode_format_str, cconf_str);
 
 	width = mode->hdisplay;
 	height = mode->vdisplay;
@@ -148,8 +148,8 @@ static int test_format(const char *test_name,
 	}
 	sleep(5);
 
-	printf("Test %s with %s on %s: PASSED\n",
+	igt_info("Test %s with %s on %s: PASSED\n",
-		test_name, mode_format_str, cconf_str);
+		 test_name, mode_format_str, cconf_str);
 	free(mode_format_str);
 	free(cconf_str);
 
@@ -161,8 +161,8 @@ static int test_format(const char *test_name,
 err2:
 	igt_remove_fb(drm_fd, &fb[0]);
 err1:
-	printf("Test %s with %s on %s: SKIPPED\n",
+	igt_info("Test %s with %s on %s: SKIPPED\n",
-		test_name, mode_format_str, cconf_str);
+		 test_name, mode_format_str, cconf_str);
 	free(mode_format_str);
 	free(cconf_str);
 

tests/kms_setmode.c

@@ -392,7 +392,7 @@ static void test_crtc_config(const struct test_config *tconf,
 	if (filter_test_id && filter_test_id != test_id)
 		return;
 
-	printf("  Test id#%d CRTC count %d\n", test_id, crtc_count);
+	igt_info("  Test id#%d CRTC count %d\n", test_id, crtc_count);
 
 	for (i = 0; i < crtc_count; i++) {
 		get_crtc_config_str(&crtcs[i], str_buf[i], sizeof(str_buf[i]));
@@ -401,7 +401,7 @@ static void test_crtc_config(const struct test_config *tconf,
 
 	if (dry_run) {
 		for (i = 0; i < crtc_count; i++)
-			printf("    %s\n", crtc_strs[i]);
+			igt_info("    %s\n", crtc_strs[i]);
 		return;
 	}
 
@@ -411,7 +411,7 @@ static void test_crtc_config(const struct test_config *tconf,
 
 		crtc = &crtcs[i];
 
-		printf("    %s\n", crtc_strs[i]);
+		igt_info("    %s\n", crtc_strs[i]);
 
 		create_fb_for_crtc(crtc, &crtc->fb_info);
 		paint_fb(&crtc->fb_info, tconf->name, crtc_strs, crtc_count, i);
@@ -623,8 +623,8 @@ static void test_combinations(const struct test_config *tconf,
 	get_combinations(tconf->resources->count_crtcs, connector_count,
 			 true, &crtc_combs);
 
-	printf("Testing: %s %d connector combinations\n", tconf->name,
+	igt_info("Testing: %s %d connector combinations\n", tconf->name,
-		connector_count);
+		 connector_count);
 	for (i = 0; i < connector_combs.count; i++) {
 		int *connector_idxs;
 		int ret;

tests/pm_pc8.c

@@ -779,8 +779,8 @@ static void setup_environment(void)
 	setup_runtime_pm();
 	setup_pc8();
 
-	printf("Runtime PM support: %d\n", has_runtime_pm);
+	igt_info("Runtime PM support: %d\n", has_runtime_pm);
-	printf("PC8 residency support: %d\n", has_pc8);
+	igt_info("PC8 residency support: %d\n", has_pc8);
 
 	igt_require(has_runtime_pm);
 }

tests/prime_nv_pcopy.c

@@ -51,12 +51,6 @@ static uint32_t memtype_intel, tile_intel_y, tile_intel_x;
 
 #define NV01_SUBC(subc, mthd) SUBC_##subc((NV01_SUBCHAN_##mthd))
 
-#if 0
-#define dbg(fmt...) fprintf(stderr, fmt);
-#else
-#define dbg(...) do { } while (0)
-#endif
-
 typedef struct {
 	uint32_t w, h;
 	uint32_t pitch, lines;
@@ -94,7 +88,7 @@ static int nv_bo_alloc(struct nouveau_bo **bo, rect *r,
 
 		dx = 1 << tile_x;
 		dy = 1 << tile_y;
-		dbg("Tiling requirements: x y %u %u\n", dx, dy);
+		igt_debug("Tiling requirements: x y %u %u\n", dx, dy);
 	}
 
 	r->w = w;
@@ -120,9 +114,12 @@ static int nv_bo_alloc(struct nouveau_bo **bo, rect *r,
 			return ret;
 		}
 
-		dbg("new flags %08x memtype %08x tile %08x\n", (*bo)->flags, (*bo)->config.nv50.memtype, (*bo)->config.nv50.tile_mode);
+		igt_debug("new flags %08x memtype %08x tile %08x\n",
+			  (*bo)->flags, (*bo)->config.nv50.memtype,
+			  (*bo)->config.nv50.tile_mode);
 		if (tile_mode == tile_intel_y || tile_mode == tile_intel_x) {
-			dbg("tile mode was: %02x, now: %02x\n", (*bo)->config.nv50.tile_mode, tile_mode);
+			igt_debug("tile mode was: %02x, now: %02x\n",
+				  (*bo)->config.nv50.tile_mode, tile_mode);
 			/* Doesn't like intel tiling much.. */
 			(*bo)->config.nv50.tile_mode = tile_mode;
 		}
@@ -140,11 +137,13 @@ static int nv_bo_alloc(struct nouveau_bo **bo, rect *r,
 			nouveau_bo_ref(NULL, bo);
 			return -1;
 		}
-		dbg("prime flags %08x memtype %08x tile %08x\n", (*bo)->flags, (*bo)->config.nv50.memtype, (*bo)->config.nv50.tile_mode);
+		igt_debug("prime flags %08x memtype %08x tile %08x\n",
+			  (*bo)->flags, (*bo)->config.nv50.memtype,
+			  (*bo)->config.nv50.tile_mode);
 		(*bo)->config.nv50.memtype = memtype;
 		(*bo)->config.nv50.tile_mode = tile_mode;
 	}
-	dbg("size: %"PRIu64"\n", (*bo)->size);
+	igt_debug("size: %"PRIu64"\n", (*bo)->size);
 
 	return ret;
 }
@@ -539,9 +538,9 @@ static int perform_copy(struct nouveau_bo *nvbo, const rect *dst,
 	int ret;
 
 	if (nvbi->config.nv50.tile_mode == tile_intel_y)
-		dbg("src is y-tiled\n");
+		igt_debug("src is y-tiled\n");
 	if (nvbo->config.nv50.tile_mode == tile_intel_y)
-		dbg("dst is y-tiled\n");
+		igt_debug("dst is y-tiled\n");
 
 	if (nouveau_pushbuf_space(push, 64, 0, 0) ||
 	    nouveau_pushbuf_refn(push, refs, 3))

tests/prime_self_import.c

@@ -298,7 +298,7 @@ static void test_reimport_close_race(void)
 
 	obj_count = get_object_count() - obj_count;
 
-	printf("leaked %i objects\n", obj_count);
+	igt_info("leaked %i objects\n", obj_count);
 
 	close(fake);
 
@@ -375,7 +375,7 @@ static void test_export_close_race(void)
 
 	obj_count = get_object_count() - obj_count;
 
-	printf("leaked %i objects\n", obj_count);
+	igt_info("leaked %i objects\n", obj_count);
 	igt_assert(obj_count == 0);
 }