DO NOT MERGE TO MAIN

Adds debugging to help debug stat mismatches detected by scrubbing.

Intentionally left unsigned to flag up in GitHub actions if it ends up in main.

Jon

diff --git a/src/osd/ECBackend.cc b/src/osd/ECBackend.cc
index e1477b737d65339a458c1ceb93442d10a01e1cb0..f805c0f9776976b56dcae0804f2ec4638e94efab 100644 (file)
--- a/src/osd/ECBackend.cc
+++ b/src/osd/ECBackend.cc
@@ -396,7 +396,10 @@ void ECBackend::handle_sub_write(
     ceph_abort_msg("Error inject - OSD down");
   }
   if (!get_parent()->pgb_is_primary())
+  {
     get_parent()->update_stats(op.stats);
+    get_parent()->log_stats(op.soid, op.stats.stats.sum, false, op.t);
+  }
   ObjectStore::Transaction localt;
   if (!op.temp_added.empty()) {
     switcher->add_temp_objs(op.temp_added);

diff --git a/src/osd/ECCommon.cc b/src/osd/ECCommon.cc
index 66e2b1542dfebc66a5479185566b700d4746e3b1..eeaea2d429d096f6f6eee04d7ac473b447aef871 100644 (file)
--- a/src/osd/ECCommon.cc
+++ b/src/osd/ECCommon.cc
@@ -789,6 +789,11 @@ void ECCommon::RMWPipeline::cache_ready(Op &op) {
     get_parent()->get_dpp(),
     get_osdmap());
 
+  get_parent()->log_stats(op.hoid,
+                          op.delta_stats,
+                          true,
+                          trans[get_parent()->whoami_shard().shard]);
+
   dout(20) << __func__ << ": written: " << written << ", op: " << op << dendl;
 
   ObjectStore::Transaction empty;

diff --git a/src/osd/ECListener.h b/src/osd/ECListener.h
index a8f02e30af0804f01d5f51f7bc43ac4dedd0f74a..eee2999596532c997781be90bb64459ff50ca2d7 100644 (file)
--- a/src/osd/ECListener.h
+++ b/src/osd/ECListener.h
@@ -167,6 +167,11 @@ struct ECListener {
      const hobject_t &soid,
      const object_stat_sum_t &delta_stats) = 0;
 
+  virtual void log_stats(hobject_t soid,
+                         object_stat_sum_t stats,
+                         bool delta,
+                         ObjectStore::Transaction& t) = 0;
+
   // new batch
   virtual bool is_missing_object(const hobject_t& oid) const = 0;
   virtual void add_local_next_event(const pg_log_entry_t& e) = 0;

diff --git a/src/osd/PGBackend.h b/src/osd/PGBackend.h
index acbff0745b23ef9f27d36a34dd1c12de78e8daf3..5009c6cbd0081fb1df926b6c649965ef1997456a 100644 (file)
--- a/src/osd/PGBackend.h
+++ b/src/osd/PGBackend.h
@@ -115,6 +115,10 @@ typedef std::shared_ptr<const OSDMap> OSDMapRef;
      virtual void apply_stats(
        const hobject_t &soid,
        const object_stat_sum_t &delta_stats) = 0;
+     virtual void log_stats(hobject_t soid,
+                            object_stat_sum_t stats,
+                            bool delta,
+                            ObjectStore::Transaction& t) = 0;
 
      /**
       * Called when a read from a std::set of replicas/primary fails

diff --git a/src/osd/PrimaryLogPG.cc b/src/osd/PrimaryLogPG.cc
index 9ef012eb930ddcf5c72b3e1a1561aa25ebdfc3b8..320a2fb3d5c7e6507bfa126f36c11d500e6a50df 100644 (file)
--- a/src/osd/PrimaryLogPG.cc
+++ b/src/osd/PrimaryLogPG.cc
@@ -9159,6 +9159,149 @@ void PrimaryLogPG::finish_ctx(OpContext *ctx, int log_op_type, int result)
   }
 }
 
+void PrimaryLogPG::log_stats(hobject_t soid,
+                             object_stat_sum_t stats,
+                             bool delta,
+                             ObjectStore::Transaction& t)
+{
+  Formatter *f = Formatter::create("json");
+
+  std::string operation = "updated to ";
+  if (delta)
+  {
+    operation = "delta applied ";
+  }
+
+  f->open_object_section("stats");
+  stats.dump(f);
+  f->close_section();
+
+  dout(20) << __func__ << ", soid: " << soid << " pg_stats " << operation;
+  f->flush(*_dout);
+  *_dout << dendl;
+
+  int set_oi_count = 0;
+
+  ObjectStore::Transaction::iterator i = t.begin();
+
+  for (int pos = 0; i.have_op(); ++pos)
+  {
+    ObjectStore::Transaction::Op *op = i.decode_op();
+    int r = 0;
+
+    if (op->op == ObjectStore::Transaction::OP_COLL_HINT) {
+      uint32_t type = op->hint;
+      bufferlist hint;
+      i.decode_bl(hint);
+      auto hiter = hint.cbegin();
+      if (type == ObjectStore::Transaction::COLL_HINT_EXPECTED_NUM_OBJECTS) {
+        uint32_t pg_num;
+        uint64_t num_objs;
+        decode(pg_num, hiter);
+        decode(num_objs, hiter);
+      }
+    }
+
+    switch (op->op) {
+    case ObjectStore::Transaction::OP_WRITE:
+      {
+        bufferlist bl;
+        i.decode_bl(bl);
+      }
+      break;
+
+    case ObjectStore::Transaction::OP_SETATTR:
+      {
+        set_oi_count++;
+
+        string name = i.decode_string();
+        if (name == OI_ATTR)
+        {
+          bufferlist bl;
+          f->open_object_section("oi");
+          i.decode_bl(bl);
+          object_info_t oi(bl);
+          oi.dump(f);
+          f->close_section();
+
+          dout(20) << __func__ << ", soid: " << soid << "."
+                   << " setattr - OI set to ";
+          f->flush(*_dout);
+          *_dout << "bl: " << bl << dendl;
+        }
+      }
+      break;
+
+    case ObjectStore::Transaction::OP_SETATTRS:
+      {
+        map<string, bufferptr> aset;
+        i.decode_attrset(aset);
+        for (map<string,bufferptr>::iterator p = aset.begin();
+             p != aset.end(); ++p)
+        {
+          if (p->first == OI_ATTR) {
+            bufferlist bl;
+            f->open_object_section("oi");
+            bl.append(p->second);
+            object_info_t oi_decode(bl);
+            oi_decode.dump(f);
+            f->close_section();
+
+            dout(20) << __func__ << ", soid: " << soid
+                     << ". setattrs - OI set to ";
+            f->flush(*_dout);
+            *_dout << "bl: " << bl << dendl;
+          }
+        }
+      }
+      break;
+
+    case ObjectStore::Transaction::OP_RMATTR:
+      {
+        string name = i.decode_string();
+      }
+      break;
+
+    case ObjectStore::Transaction::OP_OMAP_SETKEYS:
+      {
+        bufferlist bl;
+        i.decode_attrset_bl(&bl);
+      }
+      break;
+    case ObjectStore::Transaction::OP_OMAP_RMKEYS:
+      {
+        bufferlist keys_bl;
+        i.decode_keyset_bl(&keys_bl);
+      }
+      break;
+    case ObjectStore::Transaction::OP_OMAP_RMKEYRANGE:
+      {
+        i.decode_string();
+        i.decode_string();
+      }
+      break;
+    case ObjectStore::Transaction::OP_OMAP_SETHEADER:
+      {
+        bufferlist bl;
+        i.decode_bl(bl);
+      }
+      break;
+    }
+  }
+
+  if (set_oi_count > 1)
+  {
+    f->open_object_section("t");
+    t.dump(f);
+    f->close_section();
+    dout(10) << __func__ << ", soid: " << soid
+             << ". WARNING: oi set multiple ("
+             << set_oi_count << ") times in transaction ";
+    f->flush(*_dout);
+    *_dout << dendl;
+  }
+}
+
 void PrimaryLogPG::apply_stats(
   const hobject_t &soid,
   const object_stat_sum_t &delta_stats) {

diff --git a/src/osd/PrimaryLogPG.h b/src/osd/PrimaryLogPG.h
index 7418c3fd27f57a8dce82422d57f589b588c7d250..3cc56152339e8863015b08a0b90414482ef4c444 100644 (file)
--- a/src/osd/PrimaryLogPG.h
+++ b/src/osd/PrimaryLogPG.h
@@ -342,6 +342,10 @@ public:
   void apply_stats(
     const hobject_t &soid,
     const object_stat_sum_t &delta_stats) override;
+  void log_stats(hobject_t soid,
+                 object_stat_sum_t stats,
+                 bool delta,
+                 ObjectStore::Transaction& t) override;
 
   bool primary_error(const hobject_t& soid, eversion_t v);