From a69a99c241a62edd4a46e73d7b4f67a26257683e Mon Sep 17 00:00:00 2001
From: Vitaliy Filippov <vitalif@yourcmc.ru>
Date: Wed, 26 Mar 2025 14:01:54 +0300
Subject: [PATCH] trace writes

---
 src/osd/osd_primary_subops.cpp |  5 +++++
 src/osd/osd_scrub.cpp          |  8 ++++----
 tests/test_heal.sh             | 16 +++++++++++++++-
 3 files changed, 24 insertions(+), 5 deletions(-)

diff --git a/src/osd/osd_primary_subops.cpp b/src/osd/osd_primary_subops.cpp
index 244a42f9..518ccdd3 100644
--- a/src/osd/osd_primary_subops.cpp
+++ b/src/osd/osd_primary_subops.cpp
@@ -46,6 +46,11 @@ void osd_t::autosync()
 void osd_t::finish_op(osd_op_t *cur_op, int retval)
 {
     inflight_ops--;
+    if (cur_op->req.hdr.opcode == OSD_OP_WRITE)
+    {
+        printf("%jx %jx+%x p%jx v%jx r=%x\n", cur_op->req.rw.inode, cur_op->req.rw.offset, cur_op->req.rw.len,
+            cur_op->op_data ? cur_op->op_data->orig_ver : 0, cur_op->reply.rw.version, retval);
+    }
     if (cur_op->req.hdr.opcode == OSD_OP_READ ||
         cur_op->req.hdr.opcode == OSD_OP_WRITE ||
         cur_op->req.hdr.opcode == OSD_OP_DELETE)
diff --git a/src/osd/osd_scrub.cpp b/src/osd/osd_scrub.cpp
index b4480068..2be7297f 100644
--- a/src/osd/osd_scrub.cpp
+++ b/src/osd/osd_scrub.cpp
@@ -505,7 +505,7 @@ void osd_t::scrub_check_results(osd_op_t *cur_op)
                 if (votes[role] > 0 && votes[role] < votes[best])
                 {
                     printf(
-                        "[PG %u/%u] Object %jx:%jx v%ju copy on OSD %ju doesn't match %d other copies%s\n",
+                        "[PG %u/%u] Scrub error: object %jx:%jx v%ju copy on OSD %ju doesn't match %d other copies%s\n",
                         INODE_POOL(op_data->oid.inode), op_data->pg_num,
                         op_data->oid.inode, op_data->oid.stripe, op_data->fact_ver,
                         op_data->stripes[role].osd_num, votes[best],
@@ -528,7 +528,7 @@ void osd_t::scrub_check_results(osd_op_t *cur_op)
                 best = -1;
                 inconsistent = true;
                 printf(
-                    "[PG %u/%u] Object %jx:%jx v%ju is inconsistent: copies don't match. Use vitastor-cli fix to fix it\n",
+                    "[PG %u/%u] Scrub error: object %jx:%jx v%ju is inconsistent: copies don't match. Use vitastor-cli fix to fix it\n",
                     INODE_POOL(op_data->oid.inode), op_data->pg_num,
                     op_data->oid.inode, op_data->oid.stripe, op_data->fact_ver
                 );
@@ -547,7 +547,7 @@ void osd_t::scrub_check_results(osd_op_t *cur_op)
         {
             inconsistent = true;
             printf(
-                "[PG %u/%u] Object %jx:%jx v%ju is inconsistent: parity chunks don't match data. Use vitastor-cli fix to fix it\n",
+                "[PG %u/%u] Scrub error: object %jx:%jx v%ju is inconsistent: parity chunks don't match data. Use vitastor-cli fix to fix it\n",
                 INODE_POOL(op_data->oid.inode), op_data->pg_num,
                 op_data->oid.inode, op_data->oid.stripe, op_data->fact_ver
             );
@@ -574,7 +574,7 @@ void osd_t::scrub_check_results(osd_op_t *cur_op)
                 {
                     op_data->stripes[i].read_error = true;
                     printf(
-                        "[PG %u/%u] Object %jx:%jx v%ju chunk %d on OSD %ju doesn't match other chunks%s\n",
+                        "[PG %u/%u] Scrub error: object %jx:%jx v%ju chunk %d on OSD %ju doesn't match other chunks%s\n",
                         INODE_POOL(op_data->oid.inode), op_data->pg_num,
                         op_data->oid.inode, op_data->oid.stripe, op_data->fact_ver,
                         op_data->stripes[i].role, op_data->stripes[i].osd_num,
diff --git a/tests/test_heal.sh b/tests/test_heal.sh
index 84731fee..f984a30c 100755
--- a/tests/test_heal.sh
+++ b/tests/test_heal.sh
@@ -55,6 +55,20 @@ LD_PRELOAD="build/src/client/libfio_vitastor.so" \
     fio -thread -name=test -ioengine=build/src/client/libfio_vitastor.so -bsrange=4k-128k -blockalign=4k -direct=1 -iodepth=32 -fsync=256 -rw=randrw \
         -serialize_overlap=1 -randrepeat=0 -refill_buffers=1 -mirror_file=./testdata/bin/mirror.bin -etcd=$ETCD_URL -image=testimg -loops=10 -runtime=120
 
+# Wait for active/clean
+wait_up 120
+
+# Trigger scrub
+for i in $(seq 1 $PG_COUNT); do
+    $ETCDCTL put /vitastor/pg/history/1/$i `$ETCDCTL get --print-value-only /vitastor/pg/history/1/$i | jq -s -c '(.[0] // {}) + {"next_scrub":1}'`
+done
+
+# Wait for scrub to finish
+wait_condition 300 "$ETCDCTL get --prefix /vitastor/pg/history/ --print-value-only | jq -s -e '([ .[] | select(.next_scrub == 0 or .next_scrub == null) ] | length) == $PG_COUNT'" Scrubbing
+
+# Check that everything is ok
+wait_up 1
+
 qemu-img convert -S 4096 -p \
     -f raw "vitastor:etcd_host=127.0.0.1\:$ETCD_PORT/v3:image=testimg" \
     -O raw ./testdata/bin/read.bin
@@ -64,7 +78,7 @@ if ! diff -q ./testdata/bin/read.bin ./testdata/bin/mirror.bin; then
     format_error Data lost during self-heal
 fi
 
-if grep -qP 'Checksum mismatch|BUG' ./testdata/osd*.log; then
+if grep -qP 'Checksum mismatch|BUG|Scrub error' ./testdata/osd*.log; then
     format_error Checksum mismatches or BUGs detected during test
 fi