ceph_test_rados: more readable output

Signed-off-by: Sage Weil <sage@inktank.com>

diff --git a/src/test/osd/RadosModel.h b/src/test/osd/RadosModel.h
index 4f1aa4c3582ec1c3f4bec121d608ea09e4afddb0..6eb40795c9a71a6240580d8dc4f239d63ff81354 100644 (file)
--- a/src/test/osd/RadosModel.h
+++ b/src/test/osd/RadosModel.h
@@ -83,14 +83,16 @@ public:
 
 class TestOp {
 public:
+  int num;
   RadosTestContext *context;
   TestOpStat *stat;
   bool done;
-  TestOp(RadosTestContext *context,
-        TestOpStat *stat = 0) :
-    context(context),
-    stat(stat),
-    done(0)
+  TestOp(int n, RadosTestContext *context,
+        TestOpStat *stat = 0)
+    : num(n),
+      context(context),
+      stat(stat),
+      done(0)
   {}
 
   virtual ~TestOp() {};
@@ -230,6 +232,7 @@ public:
        for (list<TestOp*>::iterator i = inflight.begin();
             i != inflight.end();) {
          if ((*i)->finished()) {
+           cout << (*i)->num << ": done (" << (inflight.size()-1) << " left)" << std::endl;
            delete *i;
            inflight.erase(i++);
          } else {
@@ -238,7 +241,7 @@ public:
        }
        
        if (inflight.size() >= (unsigned) max_in_flight || (!next && !inflight.empty())) {
-         cout << "Waiting on " << inflight.size() << std::endl;
+         cout << " waiting on " << inflight.size() << std::endl;
          wait();
        } else {
          break;
@@ -488,11 +491,11 @@ public:
   librados::ObjectWriteOperation op;
   librados::AioCompletion *comp;
   bool done;
-  RemoveAttrsOp(RadosTestContext *context,
+  RemoveAttrsOp(int n, RadosTestContext *context,
               const string &oid,
-              TestOpStat *stat) :
-    TestOp(context, stat), oid(oid), comp(NULL), done(false)
-    {}
+              TestOpStat *stat)
+    : TestOp(n, context, stat), oid(oid), comp(NULL), done(false)
+  {}
 
   void _begin()
   {
@@ -577,11 +580,12 @@ public:
   librados::ObjectWriteOperation op;
   librados::AioCompletion *comp;
   bool done;
-  TmapPutOp(RadosTestContext *context,
-              const string &oid,
-              TestOpStat *stat) :
-    TestOp(context, stat), oid(oid), comp(NULL), done(false)
-    {}
+  TmapPutOp(int n,
+           RadosTestContext *context,
+           const string &oid,
+           TestOpStat *stat)
+    : TestOp(n, context, stat), oid(oid), comp(NULL), done(false)
+  {}
 
   void _begin()
   {
@@ -670,11 +674,13 @@ public:
   librados::ObjectWriteOperation op;
   librados::AioCompletion *comp;
   bool done;
-  SetAttrsOp(RadosTestContext *context,
-              const string &oid,
-              TestOpStat *stat) :
-    TestOp(context, stat), oid(oid), comp(NULL), done(false)
-    {}
+  SetAttrsOp(int n,
+            RadosTestContext *context,
+            const string &oid,
+            TestOpStat *stat)
+    : TestOp(n, context, stat),
+      oid(oid), comp(NULL), done(false)
+  {}
 
   void _begin()
   {
@@ -763,11 +769,12 @@ public:
   uint64_t waiting_on;
   uint64_t last_acked_tid;
 
-  WriteOp(RadosTestContext *context, 
+  WriteOp(int n,
+         RadosTestContext *context,
          const string &oid,
-         TestOpStat *stat = 0) : 
-    TestOp(context, stat),
-    oid(oid), waiting_on(0), last_acked_tid(0)
+         TestOpStat *stat = 0)
+    : TestOp(n, context, stat),
+      oid(oid), waiting_on(0), last_acked_tid(0)
   {}
                
   void _begin()
@@ -800,12 +807,12 @@ public:
 
     int r = context->io_ctx.selfmanaged_snap_set_write_ctx(context->seq, snapset);
     if (r) {
-      cerr << "r is " << r << " snapset is " << snapset << " seq is " << context->seq << std::endl;
+      cerr << " r is " << r << " snapset is " << snapset << " seq is " << context->seq << std::endl;
       assert(0);
     }
 
     waiting_on = ranges.num_intervals();
-    cout << "waiting_on = " << waiting_on << std::endl;
+    //cout << " waiting_on = " << waiting_on << std::endl;
     ContentsGenerator::iterator gen_pos = context->cont_gen.get_iterator(cont);
     uint64_t tid = 1;
     for (interval_set<uint64_t>::iterator i = ranges.begin(); 
@@ -818,7 +825,7 @@ public:
       }
       assert(to_write.length() == i.get_len());
       assert(to_write.length() > 0);
-      std::cout << "Writing " << context->prefix+oid << " from " << i.get_start()
+      std::cout << num << ":  writing " << context->prefix+oid << " from " << i.get_start()
                << " to " << i.get_len() + i.get_start() << " tid " << tid
                << " ranges are " << ranges << std::endl;
       pair<TestOp*, TestOp::CallbackInfo*> *cb_arg =
@@ -838,7 +845,7 @@ public:
     context->state_lock.Lock();
     uint64_t tid = info->id;
 
-    cout << "finishing write tid " << tid << " to " << context->prefix + oid << std::endl;
+    cout << num << ":  finishing write tid " << tid << " to " << context->prefix + oid << std::endl;
 
     if (tid <= last_acked_tid) {
       cerr << "Error: finished tid " << tid
@@ -889,10 +896,11 @@ class DeleteOp : public TestOp {
 public:
   string oid;
 
-  DeleteOp(RadosTestContext *context,
+  DeleteOp(int n,
+          RadosTestContext *context,
           const string &oid,
-          TestOpStat *stat = 0) :
-    TestOp(context, stat), oid(oid)
+          TestOpStat *stat = 0)
+    : TestOp(n, context, stat), oid(oid)
   {}
 
   void _begin()
@@ -970,16 +978,17 @@ public:
   bufferlist header;
 
   map<string, bufferlist> xattrs;
-  ReadOp(RadosTestContext *context, 
+  ReadOp(int n,
+        RadosTestContext *context,
         const string &oid,
-        TestOpStat *stat = 0) : 
-    TestOp(context, stat),
-    completion(NULL),
-    oid(oid),
-    old_value(&context->cont_gen),
-    snap(0),
-    retval(0),
-    attrretval(0)
+        TestOpStat *stat = 0)
+    : TestOp(n, context, stat),
+      completion(NULL),
+      oid(oid),
+      old_value(&context->cont_gen),
+      snap(0),
+      retval(0),
+      attrretval(0)
   {}
                
   void _begin()
@@ -1002,9 +1011,9 @@ public:
     if (ctx) {
       assert(old_value.exists);
       TestAlarm alarm;
-      std::cerr << "about to start" << std::endl;
+      std::cerr << num << ":  about to start" << std::endl;
       ctx->start();
-      std::cerr << "started" << std::endl;
+      std::cerr << num << ":  started" << std::endl;
       bufferlist bl;
       context->io_ctx.set_notify_timeout(600);
       int r = context->io_ctx.notify(context->prefix+oid, 0, bl);
@@ -1012,7 +1021,7 @@ public:
        std::cerr << "r is " << r << std::endl;
        assert(0);
       }
-      std::cerr << "notified, waiting" << std::endl;
+      std::cerr << num << ":  notified, waiting" << std::endl;
       ctx->wait();
     }
     if (snap >= 0) {
@@ -1059,7 +1068,7 @@ public:
     uint64_t version = completion->get_version64();
     if (int err = completion->get_return_value()) {
       if (!(err == -ENOENT && old_value.deleted())) {
-       cerr << "Error: oid " << oid << " read returned error code "
+       cerr << num << ": Error: oid " << oid << " read returned error code "
             << err << std::endl;
       }
     } else {
@@ -1068,16 +1077,16 @@ public:
        ContDesc to_check;
        bufferlist::iterator p = result.begin();
        if (!context->cont_gen.read_header(p, to_check)) {
-         cerr << "Unable to decode oid " << oid << " at snap " << context->current_snap << std::endl;
+         cerr << num << ": Unable to decode oid " << oid << " at snap " << context->current_snap << std::endl;
          context->errors++;
        }
        if (to_check != old_value.most_recent()) {
-         cerr << "Found incorrect object contents " << to_check
+         cerr << num << ": Found incorrect object contents " << to_check
               << ", expected " << old_value.most_recent() << " oid " << oid << std::endl;
          context->errors++;
        }
        if (!old_value.check(result)) {
-         cerr << "Object " << oid << " contents " << to_check << " corrupt" << std::endl;
+         cerr << num << ": Object " << oid << " contents " << to_check << " corrupt" << std::endl;
          context->errors++;
        }
        if (context->errors) assert(0);
@@ -1085,28 +1094,28 @@ public:
 
       // Attributes
       if (!(old_value.header == header)) {
-       cerr << "oid: " << oid << " header does not match, old size: "
+       cerr << num << ": oid " << oid << " header does not match, old size: "
             << old_value.header.length() << " new size " << header.length()
             << std::endl;
        assert(old_value.header == header);
       }
       if (omap.size() != old_value.attrs.size()) {
-       cerr << "oid: " << oid << " tmap.size() is " << omap.size()
+       cerr << num << ": oid " << oid << " tmap.size() is " << omap.size()
             << " and old is " << old_value.attrs.size() << std::endl;
        assert(omap.size() == old_value.attrs.size());
       }
       if (omap_keys.size() != old_value.attrs.size()) {
-       cerr << "oid: " << oid << " tmap.size() is " << omap_keys.size()
+       cerr << num << ": oid " << oid << " tmap.size() is " << omap_keys.size()
             << " and old is " << old_value.attrs.size() << std::endl;
        assert(omap_keys.size() == old_value.attrs.size());
       }
       if (xattrs.size() != old_value.attrs.size()) {
-       cerr << "oid: " << oid << " xattrs.size() is " << xattrs.size()
+       cerr << num << ": oid " << oid << " xattrs.size() is " << xattrs.size()
             << " and old is " << old_value.attrs.size() << std::endl;
        assert(xattrs.size() == old_value.attrs.size());
       }
       if (version != old_value.version) {
-       cerr << "oid: " << oid << " version is " << version
+       cerr << num << ": oid " << oid << " version is " << version
             << " and expected " << old_value.version << std::endl;
        assert(version == old_value.version);
       }
@@ -1163,9 +1172,10 @@ public:
 
 class SnapCreateOp : public TestOp {
 public:
-  SnapCreateOp(RadosTestContext *context,
-              TestOpStat *stat = 0) :
-    TestOp(context, stat)
+  SnapCreateOp(int n,
+              RadosTestContext *context,
+              TestOpStat *stat = 0)
+    : TestOp(n, context, stat)
   {}
 
   void _begin()
@@ -1201,11 +1211,11 @@ public:
 class SnapRemoveOp : public TestOp {
 public:
   int to_remove;
-  SnapRemoveOp(RadosTestContext *context,
+  SnapRemoveOp(int n, RadosTestContext *context,
               int snap,
-              TestOpStat *stat = 0) :
-    TestOp(context, stat),
-    to_remove(snap)
+              TestOpStat *stat = 0)
+    : TestOp(n, context, stat),
+      to_remove(snap)
   {}
 
   void _begin()
@@ -1241,11 +1251,12 @@ public:
 class WatchOp : public TestOp {
   string oid;
 public:
-  WatchOp(RadosTestContext *context,
-            const string &_oid,
-            TestOpStat *stat = 0) :
-    TestOp(context, stat),
-    oid(_oid)
+  WatchOp(int n,
+         RadosTestContext *context,
+         const string &_oid,
+         TestOpStat *stat = 0)
+    : TestOp(n, context, stat),
+      oid(_oid)
   {}
 
   void _begin()
@@ -1318,13 +1329,14 @@ public:
   librados::ObjectWriteOperation op;
   librados::AioCompletion *comp;
 
-  RollbackOp(RadosTestContext *context,
+  RollbackOp(int n,
+            RadosTestContext *context,
             const string &_oid,
             int snap,
-            TestOpStat *stat = 0) :
-    TestOp(context, stat),
-    oid(_oid),
-    roll_back_to(snap), done(false)
+            TestOpStat *stat = 0)
+    : TestOp(n, context, stat),
+      oid(_oid),
+      roll_back_to(snap), done(false)
   {}
 
   void _begin()
@@ -1395,11 +1407,13 @@ public:
   int snap;
   bool done;
   tid_t tid;
-  CopyFromOp(RadosTestContext *context,
+  CopyFromOp(int n,
+            RadosTestContext *context,
             const string &oid,
             const string &oid_src,
             TestOpStat *stat)
-    : TestOp(context, stat), oid(oid), oid_src(oid_src),
+    : TestOp(n, context, stat),
+      oid(oid), oid_src(oid_src),
       src_value(&context->cont_gen),
       comp(NULL), done(false), tid(0)
   {}
@@ -1442,7 +1456,7 @@ public:
     done = true;
     int r;
     assert(comp->is_complete());
-    cout << "finishing copy_from tid " << tid << " to " << context->prefix + oid << std::endl;
+    cout << num << ":  finishing copy_from tid " << tid << " to " << context->prefix + oid << std::endl;
     if ((r = comp->get_return_value())) {
       if (!(r == -ENOENT && src_value.deleted())) {
        cerr << "Error: oid " << oid << " copy_from " << oid_src << " returned error code "

diff --git a/src/test/osd/TestRados.cc b/src/test/osd/TestRados.cc
index 1deee23aa2c4ed06cb00d6ccaaccbe0550bec1dc..1b6bd073a1264b7ac7ecf7e88b1428a81989a563 100644 (file)
--- a/src/test/osd/TestRados.cc
+++ b/src/test/osd/TestRados.cc
@@ -48,8 +48,8 @@ public:
     if (m_op <= m_objects) {
       stringstream oid;
       oid << m_op;
-      cout << m_op << ": Writing initial " << oid.str() << std::endl;
-      return new WriteOp(&context, oid.str());
+      cout << m_op << ": write initial oid " << oid.str() << std::endl;
+      return new WriteOp(m_op, &context, oid.str());
     } else if (m_op >= m_ops) {
       return NULL;
     }
@@ -71,7 +71,6 @@ public:
           it != m_weight_sums.end();
           ++it) {
        if (rand_val < it->second) {
-         cout << m_op << ": ";
          retval = gen_op(context, it->first);
          break;
        }
@@ -85,37 +84,39 @@ private:
   TestOp *gen_op(RadosTestContext &context, TestOpType type)
   {
     string oid, oid2;
-    cout << "oids not in use " << context.oid_not_in_use.size() << std::endl;
+    //cout << "oids not in use " << context.oid_not_in_use.size() << std::endl;
     assert(context.oid_not_in_use.size());
+
+    cout << m_op << ": ";
     switch (type) {
     case TEST_OP_READ:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Reading " << oid << std::endl;
-      return new ReadOp(&context, oid, m_stats);
+      cout << "read oid " << oid << std::endl;
+      return new ReadOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_WRITE:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Writing " << oid << " current snap is "
+      cout << "write oid " << oid << " current snap is "
           << context.current_snap << std::endl;
-      return new WriteOp(&context, oid, m_stats);
+      return new WriteOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_DELETE:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Deleting " << oid << " current snap is "
+      cout << "delete oid " << oid << " current snap is "
           << context.current_snap << std::endl;
-      return new DeleteOp(&context, oid, m_stats);
+      return new DeleteOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_SNAP_CREATE:
-      cout << "Snapping" << std::endl;
-      return new SnapCreateOp(&context, m_stats);
+      cout << "snap_create" << std::endl;
+      return new SnapCreateOp(m_op, &context, m_stats);
 
     case TEST_OP_SNAP_REMOVE:
       if (context.snaps.empty()) {
        return NULL;
       } else {
        int snap = rand_choose(context.snaps)->first;
-       cout << "RemovingSnap " << snap << std::endl;
-       return new SnapRemoveOp(&context, snap, m_stats);
+       cout << "snap_remove snap " << snap << std::endl;
+       return new SnapRemoveOp(m_op, &context, snap, m_stats);
       }
 
     case TEST_OP_ROLLBACK:
@@ -124,40 +125,40 @@ private:
       } else {
        int snap = rand_choose(context.snaps)->first;
        string oid = *(rand_choose(context.oid_not_in_use));
-       cout << "RollingBack " << oid << " to " << snap << std::endl;
-        return new RollbackOp(&context, oid, snap);
+       cout << "rollback oid " << oid << " to " << snap << std::endl;
+        return new RollbackOp(m_op, &context, oid, snap);
       }
 
     case TEST_OP_SETATTR:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Setting attrs on " << oid
+      cout << "setattr oid " << oid
           << " current snap is " << context.current_snap << std::endl;
-      return new SetAttrsOp(&context, oid, m_stats);
+      return new SetAttrsOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_RMATTR:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Removing attrs on " << oid
+      cout << "rmattr oid " << oid
           << " current snap is " << context.current_snap << std::endl;
-      return new RemoveAttrsOp(&context, oid, m_stats);
+      return new RemoveAttrsOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_TMAPPUT:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Setting tmap on " << oid
+      cout << "tmapput oid " << oid
           << " current snap is " << context.current_snap << std::endl;
-      return new TmapPutOp(&context, oid, m_stats);
+      return new TmapPutOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_WATCH:
       oid = *(rand_choose(context.oid_not_in_use));
-      cout << "Watching " << oid
+      cout << "watch oid " << oid
           << " current snap is " << context.current_snap << std::endl;
-      return new WatchOp(&context, oid, m_stats);
+      return new WatchOp(m_op, &context, oid, m_stats);
 
     case TEST_OP_COPY_FROM:
       oid = *(rand_choose(context.oid_not_in_use));
       oid2 = *(rand_choose(context.oid_not_in_use));
-      cout << "copy_from " << oid << " from " << oid2
+      cout << "copy_from oid " << oid << " from oid " << oid2
           << " current snap is " << context.current_snap << std::endl;
-      return new CopyFromOp(&context, oid, oid2, m_stats);
+      return new CopyFromOp(m_op, &context, oid, oid2, m_stats);
 
     default:
       cerr << "Invalid op type " << type << std::endl;