btrfs-progs: Fix wrong address accessing by subthread in btrfs-convert

From: Zhao Lei <[email protected]>

It is v3 patchset of:
Fix wrong address accessing by subthread in btrfs-convert.

Changelog v2->v3:
1: Add $TOP path prefix to btrfs-convert command in:
[PATCH v2 7/7] btrfs-progs: Introduce a misc test for thread conflict in btrfs-convert
To check prog in btrfs source dir.

Changelog v1->v2:
1: Move bug test script from patch description into a single script in
test/misc-tests, suggested-by: David Sterba <[email protected]>
2: Move code for creating loop device to common [PATCH 6/7]

Zhao Lei (7):
btrfs-progs: Fix wrong address accessing by subthread in btrfs-convert
btrfs-progs: Move close timer handle code to line after sub process
exit
btrfs-progs: Remove cleanup-timer code for btrfs-convert
btrfs-progs: resst info->periodic.timer_fd's value after free
btrfs-progs: Set info->periodic.timer_fd to 0 in init-fail
btrfs-progs: Move code to create loop device to common
btrfs-progs: Introduce a misc test for thread conflict in
btrfs-convert

 btrfs-convert.c                                    |  4 +---
 task-utils.c                                       | 22 ++++++++++++++--------
 tests/common                                       | 16 ++++++++++++++++
 tests/fsck-tests/013-extent-tree-rebuild/test.sh   | 11 +----------
 tests/misc-tests/001-btrfstune-features/test.sh    | 11 +----------
 tests/misc-tests/002-uuid-rewrite/test.sh          | 11 +----------
 tests/misc-tests/003-zero-log/test.sh              | 11 +----------
 .../misc-tests/004-convert-thread-conflict/test.sh | 14 ++++++++++++++
 8 files changed, 49 insertions(+), 51 deletions(-)
 create mode 100755 tests/misc-tests/004-convert-thread-conflict/test.sh

1.8.5.1

From: Zhao Lei <[email protected]>

btrfs-convert sometimes show 'Assertion failed' in converting a nearly blank file system, as:
create btrfs filesystem:

          blocksize: 4096
          nodesize:  16384
          features:  extref, skinny-metadata (default)

creating btrfs metadata.

creating ext2fs image file.
trans 7 running 5
ctree.c:363: btrfs_cow_block: Assertion 1 failed. btrfs-convert(btrfs_cow_block+0x92)[0x40acaf] btrfs-convert(btrfs_search_slot+0x1cb)[0x40c50f] btrfs-convert(btrfs_csum_file_block+0x20f)[0x41d83a] btrfs-convert[0x43422d] btrfs-convert[0x4342cd] btrfs-convert[0x4345ca] btrfs-convert[0x434767] btrfs-convert[0x435770] btrfs-convert[0x439748] btrfs-convert(main+0x13f8)[0x43b09d] /lib64/libc.so.6(__libc_start_main+0xfd)[0x335e01ecdd] btrfs-convert[0x407649]

Reason is complex:
1: main thread allocated a block of memory,
shared with sub thread
2: main thread killed sub thread, and free above memory 3: main thread malloc a new one(in same address),
and use it
4: sub thread(which is not really quit), write into
this address, and caused this bug.

By adding some debug lines into code, we can see following output:
create btrfs filesystem:

          blocksize: 4096
          nodesize:  16384
          features:  extref, skinny-metadata (default)
  creating btrfs metadata.
  1:  ctx(0x7ffe1abde230)->info=0xc65b80
  2:  task_period_start: will create periodic.timer_fd
  3:  task_stop: info->periodic.timer_fd = NULL
  4:  task_stop: begin pthread_cancel info->id=-1746053376
  5:  task_stop: done pthread_cancel ret=0
  6:  task_stop: begin info->postfn
  7:  task_period_stop: periodic.timer_fd NULL
  8:  task_stop: done info->postfn
  9:  task_stop: done all
  10: creating ext2fs image file.
  trans 7 running 5
  11: task_period_start: create periodic.timer_fd done info->periodic.timer_fd(0xc65b80)=7
  12: btrfs_cow_block: root->fs_info->generation(0xc63568) = 5 trans->transid(0xc65b80)=7
  13: ctree.c:368: btrfs_cow_block: Assertion `1` failed.
  ./btrfs-convert(btrfs_cow_block+0xda)[0x40ad37]
  ./btrfs-convert(btrfs_search_slot+0x1cb)[0x40c5b4]
  ./btrfs-convert(btrfs_insert_empty_items+0xac)[0x40d9f6]
  ./btrfs-convert(btrfs_record_file_extent+0xc0)[0x4183fe]
  ./btrfs-convert[0x435796]
  ./btrfs-convert[0x439b0c]
  ./btrfs-convert(main+0x13f8)[0x43b45d]
  /lib64/libc.so.6(__libc_start_main+0xfd)[0x335e01ecdd]
  ./btrfs-convert[0x407689]
  Conclusion:
  a: subthread should exit before step 5, but it is still running
     in step 11
  b: task_stop() hadn't close periodic.timer_fd in step3,
     because periodic.timer_fd is not initialized yet.
  c. address of 0xc65b80 is overwrited by subthread in step 11,
     but this address is freed and re-malloc by main thread
     before step 10, and used for trans->transid.
  d: trans->transid which is overwrite by subthread caused error
     in step 13.

Fix:
pthread_cancel() only send a cancellation request to the thread, thread will quit in next cancellation point by default. To make sub thread quit in time, this patch add pthread_join() after pthread_cancel() call.
And to make pthread_join() works, pthread_detach() is removed.

---
 task-utils.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

index 10e3f0f..0390a69 100644
@@ -50,9 +50,7 @@ int task_start(struct task_info *info)
 	ret = pthread_create(&info->id, NULL, info->threadfn,
 			     info->private_data);
 
-	if (ret == 0)
-		pthread_detach(info->id);
-	else
+	if (ret)
 		info->id = -1;
 
 	return ret;

@@ -66,8 +64,10 @@ void task_stop(struct task_info *info)
 	if (info->periodic.timer_fd)
 		close(info->periodic.timer_fd);
 
-	if (info->id > 0)
+	if (info->id > 0) {
 		pthread_cancel(info->id);
+		pthread_join(info->id, NULL);
+	}
 
 	if (info->postfn)
 		info->postfn(info->private_data);

1.8.5.1

From: Zhao Lei <[email protected]>

The timer handle have possibility in using by sub thread, better to close it after sub process exit.

---
 task-utils.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

index 0390a69..17fd573 100644
@@ -61,14 +61,14 @@ void task_stop(struct task_info *info)
 	if (!info)
 		return;
 
-	if (info->periodic.timer_fd)
-		close(info->periodic.timer_fd);
-
 	if (info->id > 0) {
 		pthread_cancel(info->id);
 		pthread_join(info->id, NULL);
 	}
 
+	if (info->periodic.timer_fd)
+		close(info->periodic.timer_fd);
+
 	if (info->postfn)
 		info->postfn(info->private_data);
 }

1.8.5.1

From: Zhao Lei <[email protected]>

No need to close timer handle afain in subthread-close-callback, it is closed by task_stop() automatically.

This patch also add a fflush() to make log output on time.

---
 btrfs-convert.c | 4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

index b89c685..7dfab7d 100644
@@ -71,10 +71,8 @@ static void *print_copied_inodes(void *p)
 
 static int after_copied_inodes(void *p)
 {
-	struct task_ctx *priv = p;
-
 	printf("\n");
-	task_period_stop(priv->info);
+	fflush(stdout);
 
 	return 0;
 }

1.8.5.1

From: Zhao Lei <[email protected]>

task_period_stop() is used to close a timer explicitly, to avoid the timer handle closed again by task_stop(), we should reset its value after close.

Also add value-reset for info->id for safe.

---
 task-utils.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

index 17fd573..768be94 100644
@@ -64,10 +64,13 @@ void task_stop(struct task_info *info)
 	if (info->id > 0) {
 		pthread_cancel(info->id);
 		pthread_join(info->id, NULL);
+		info->id = -1;
 	}
 
-	if (info->periodic.timer_fd)
+	if (info->periodic.timer_fd) {
 		close(info->periodic.timer_fd);
+		info->periodic.timer_fd = 0;
+	}
 
 	if (info->postfn)
 		info->postfn(info->private_data);

@@ -130,5 +133,6 @@ void task_period_stop(struct task_info *info)
 	if (info->periodic.timer_fd) {
 		timerfd_settime(info->periodic.timer_fd, 0, NULL, NULL);
 		close(info->periodic.timer_fd);
+		info->periodic.timer_fd = -1;
 	}
 }

1.8.5.1

From: Zhao Lei <[email protected]>

In current code, (info->periodic.timer_fd == 0) means it is not valid, as:

  if (info->periodic.timer_fd) {
      close(info->periodic.timer_fd);
      ...

We need set its value from -1 to 0 in create-fail case, to make code like above works.

---
 task-utils.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

index 768be94..58f5195 100644
@@ -94,8 +94,10 @@ int task_period_start(struct task_info *info, unsigned int period_ms)
 		return -1;
 
 	info->periodic.timer_fd = timerfd_create(CLOCK_MONOTONIC, 0);
-	if (info->periodic.timer_fd == -1)
+	if (info->periodic.timer_fd == -1) {
+		info->periodic.timer_fd = 0;
 		return info->periodic.timer_fd;
+	}
 
 	info->periodic.wakeups_missed = 0;
 

1.8.5.1

From: Zhao Lei <[email protected]>

This code block is common used, move it to common function will make code clean.

---
 tests/common                                     | 16 ++++++++++++++++
 tests/fsck-tests/013-extent-tree-rebuild/test.sh | 11 +----------
 tests/misc-tests/001-btrfstune-features/test.sh  | 11 +----------
 tests/misc-tests/002-uuid-rewrite/test.sh        | 11 +----------
 tests/misc-tests/003-zero-log/test.sh            | 11 +----------
 5 files changed, 20 insertions(+), 40 deletions(-)

index 899ec7b..2d337b0 100644
@@ -142,3 +142,19 @@ setup_root_helper()
 	fi
 	SUDO_HELPER=root_helper
 }
+
+prepare_test_dev()
+{
+	# num[K/M/G/T...]
+	local size="$1"
+
+	[[ "$TEST_DEV" ]] && return
+	[[ "$size" ]] || size='1G'
+
+	echo "\$TEST_DEV not given, use $TOP/test/test.img as fallback" >> \
+		$RESULTS
+	TEST_DEV="$TOP/tests/test.img"
+
+	truncate -s "$size" "$TEST_DEV" || _not_run "create file for loop device failed"
+}
+

index 3290cd7..88a66cc 100755
@@ -5,16 +5,7 @@ source $TOP/tests/common
 check_prereq btrfs-debug-tree
 check_prereq mkfs.btrfs
 setup_root_helper
-
-if [ -z $TEST_DEV ]; then
-	echo "\$TEST_DEV not given, use $TOP/test/test.img as fallback" >> \
-		$RESULTS
-	TEST_DEV="$TOP/tests/test.img"
-
-	# Need at least 1G to avoid mixed block group, which extent tree
-	# rebuild doesn't support.
-	run_check truncate -s 1G $TEST_DEV
-fi
+prepare_test_dev 1G
 
 if [ -z $TEST_MNT ];then
 	echo "    [NOTRUN] extent tree rebuild, need TEST_MNT variant"

index c9981e6..ea33954 100755
@@ -7,16 +7,7 @@ check_prereq btrfs-debug-tree
 check_prereq btrfs-show-super
 check_prereq mkfs.btrfs
 setup_root_helper
-
-if [ -z $TEST_DEV ]; then
-	echo "\$TEST_DEV not given, use $TOP/test/test.img as fallback" >> \
-		$RESULTS
-	TEST_DEV="$TOP/tests/test.img"
-
-	# Need at least 1G to avoid mixed block group, which extent tree
-	# rebuild doesn't support.
-	run_check truncate -s 1G $TEST_DEV
-fi
+prepare_test_dev
 
 if [ -z $TEST_MNT ];then
 	echo "    [NOTRUN] extent tree rebuild, need TEST_MNT variant"

index 6c2a393..bffa9b8 100755
@@ -7,16 +7,7 @@ check_prereq btrfs-debug-tree
 check_prereq btrfs-show-super
 check_prereq mkfs.btrfs
 check_prereq btrfstune
-
-if [ -z $TEST_DEV ]; then
-	echo "\$TEST_DEV not given, use $TOP/test/test.img as fallback" >> \
-		$RESULTS
-	TEST_DEV="$TOP/tests/test.img"
-
-	# Need at least 1G to avoid mixed block group, which extent tree
-	# rebuild doesn't support.
-	run_check truncate -s 1G $TEST_DEV
-fi
+prepare_test_dev
 
 if [ -z $TEST_MNT ];then
 	echo "    [NOTRUN] extent tree rebuild, need TEST_MNT variant"

index da5b351..edab5db 100755
@@ -6,16 +6,7 @@ source $TOP/tests/common
 check_prereq btrfs-show-super
 check_prereq mkfs.btrfs
 check_prereq btrfs
-
-if [ -z $TEST_DEV ]; then
-	echo "\$TEST_DEV not given, use $TOP/test/test.img as fallback" >> \
-		$RESULTS
-	TEST_DEV="$TOP/tests/test.img"
-
-	# Need at least 1G to avoid mixed block group, which extent tree
-	# rebuild doesn't support.
-	run_check truncate -s 1G $TEST_DEV
-fi
+prepare_test_dev
 
 if [ -z $TEST_MNT ];then
 	echo "    [NOTRUN] extent tree rebuild, need TEST_MNT variant"

1.8.5.1

From: Zhao Lei <[email protected]>

Current code of btrfs-convert have a bug of thread conflict, which caused invalid memory accessing between threads, and make program panic.

This patch add a test item for above bug, as:

 # ./misc-tests.sh
    [TEST]   001-btrfstune-features
    [TEST]   002-uuid-rewrite
    [TEST]   003-zero-log
    [TEST]   004-convert-thread-conflict
 failed: btrfs-convert /root/btrfsprogs/tests/test.img
 test failed for case 004-convert-thread-conflict
 #
 # cat misc-tests-results.txt
 ...
 ############### btrfs-convert /root/btrfsprogs/tests/test.img
 trans 7 running 5
 ctree.c:363: btrfs_cow_block: Assertion `1` failed.
 btrfs-convert(btrfs_cow_block+0x92)[0x40acaf]
 btrfs-convert(btrfs_search_slot+0x1cb)[0x40c50f]
 btrfs-convert(btrfs_csum_file_block+0x20f)[0x41d83a]
 btrfs-convert[0x43422d]
 btrfs-convert[0x4342cd]
 btrfs-convert[0x4345ca]
 btrfs-convert[0x434767]
 btrfs-convert[0x435770]
 btrfs-convert[0x439748]
 btrfs-convert(main+0x13f8)[0x43b09d]
 /lib64/libc.so.6(__libc_start_main+0xfd)[0x335e01ecdd]
 btrfs-convert[0x407649]
 create btrfs filesystem:
         blocksize: 4096
         nodesize:  16384
         features:  extref, skinny-metadata (default)
 creating btrfs metadata.

creating ext2fs image file.
failed: btrfs-convert /root/btrfsprogs/tests/test.img test failed for case 004-convert-thread-conflict #

Note that this bug is not happened every time, especilly in slow device as loop(slow cpu with fast block device is likely to trigger). I set loop count to 20 to make bug happened in 90% tests.

---
 tests/misc-tests/004-convert-thread-conflict/test.sh | 14 ++++++++++++++
 1 file changed, 14 insertions(+)
 create mode 100755 tests/misc-tests/004-convert-thread-conflict/test.sh

new file mode 100755
index 0000000..09ac8a3
@@ -0,0 +1,14 @@
+#!/bin/bash
+# test convert-thread-conflict
+
+source $TOP/tests/common
+
+check_prereq btrfs
+mkfs.ext4 -V &>/dev/null || _not_run "mkfs.ext4 not found"
+prepare_test_dev 1G
+
+for ((i = 0; i < 20; i++)); do
+	echo "loop $i" >>$RESULTS
+	mkfs.ext4 -F "$TEST_DEV" &>>$RESULTS || _not_run "mkfs.ext4 failed"
+	run_check $TOP/btrfs-convert "$TEST_DEV"
+done

1.8.5.1

Replaced the existing and added the new ones, thanks!