rgw: refactor logging in gc and lc

RGWGC and RGWLC are now DoutPrefixProviders

Signed-off-by: Ali Maredia <amaredia@redhat.com>

diff --git a/src/rgw/rgw_gc.cc b/src/rgw/rgw_gc.cc
index 9c770ea621be080eab55e3058eddb6dd5244d619..c6519da74cef91c41f53ed4f8e7b6faac9147f71 100644 (file)
--- a/src/rgw/rgw_gc.cc
+++ b/src/rgw/rgw_gc.cc
@@ -128,6 +128,7 @@ int RGWGC::list(int *index, string& marker, uint32_t max, bool expired_only, std
 }
 
 class RGWGCIOManager {
+  const DoutPrefixProvider* dpp;
   CephContext *cct;
   RGWGC *gc;
 
@@ -150,7 +151,8 @@ class RGWGCIOManager {
   size_t max_aio{MAX_AIO_DEFAULT};
 
 public:
-  RGWGCIOManager(CephContext *_cct, RGWGC *_gc) : cct(_cct),
+  RGWGCIOManager(const DoutPrefixProvider* _dpp, CephContext *_cct, RGWGC *_gc) : dpp(_dpp),
+                                                  cct(_cct),
                                                   gc(_gc),
                                                   remove_tags(cct->_conf->rgw_gc_max_objs) {
     max_aio = cct->_conf->rgw_gc_max_concurrent_io;
@@ -194,13 +196,13 @@ public:
 
     if (io.type == IO::IndexIO) {
       if (ret < 0) {
-        ldout(cct, 0) << "WARNING: gc cleanup of tags on gc shard index=" << io.index << " returned error, ret=" << ret << dendl;
+        ldpp_dout(dpp, 0) << "WARNING: gc cleanup of tags on gc shard index=" << io.index << " returned error, ret=" << ret << dendl;
       }
       goto done;
     }
 
     if (ret < 0) {
-      ldout(cct, 0) << "WARNING: could not remove oid=" << io.oid << ", ret=" << ret << dendl;
+      ldpp_dout(dpp, 0) << "WARNING: could not remove oid=" << io.oid << ", ret=" << ret << dendl;
       goto done;
     }
 
@@ -239,7 +241,7 @@ done:
       /* we already cleared list of tags, this prevents us from ballooning in case of
        * a persistent problem
        */
-      ldout(cct, 0) << "WARNING: failed to remove tags on gc shard index=" << index << " ret=" << ret << dendl;
+      ldpp_dout(dpp, 0) << "WARNING: failed to remove tags on gc shard index=" << index << " ret=" << ret << dendl;
       return;
     }
     ios.push_back(index_io);
@@ -273,7 +275,7 @@ int RGWGC::process(int index, int max_secs, bool expired_only,
 
   int ret = l.lock_exclusive(&store->gc_pool_ctx, obj_names[index]);
   if (ret == -EBUSY) { /* already locked by another gc processor */
-    dout(10) << "RGWGC::process() failed to acquire lock on " << obj_names[index] << dendl;
+    ldpp_dout(this, 10) << "RGWGC::process() failed to acquire lock on " << obj_names[index] << dendl;
     return 0;
   }
   if (ret < 0)
@@ -313,7 +315,7 @@ int RGWGC::process(int index, int max_secs, bool expired_only,
           ctx = new IoCtx;
          ret = rgw_init_ioctx(store->get_rados_handle(), obj.pool, *ctx);
          if (ret < 0) {
-           dout(0) << "ERROR: failed to create ioctx pool=" << obj.pool << dendl;
+           ldpp_dout(this, 0) << "ERROR: failed to create ioctx pool=" << obj.pool << dendl;
            continue;
          }
           last_pool = obj.pool;
@@ -323,13 +325,13 @@ int RGWGC::process(int index, int max_secs, bool expired_only,
 
         const string& oid = obj.key.name; /* just stored raw oid there */
 
-       dout(5) << "gc::process: removing " << obj.pool << ":" << obj.key.name << dendl;
+       ldpp_dout(this, 5) << "gc::process: removing " << obj.pool << ":" << obj.key.name << dendl;
        ObjectWriteOperation op;
        cls_refcount_put(op, info.tag, true);
 
         ret = io_manager.schedule_io(ctx, oid, &op, index, info.tag);
         if (ret < 0) {
-          ldout(store->ctx(), 0) << "WARNING: failed to schedule deletion for oid=" << oid << dendl;
+          ldpp_dout(this, 0) << "WARNING: failed to schedule deletion for oid=" << oid << dendl;
         }
 
         if (going_down()) // leave early, even if tag isn't removed, it's ok
@@ -353,7 +355,7 @@ int RGWGC::process(bool expired_only)
 
   const int start = ceph::util::generate_random_number(0, max_objs - 1);
 
-  RGWGCIOManager io_manager(store->ctx(), this);
+  RGWGCIOManager io_manager(this, store->ctx(), this);
 
   for (int i = 0; i < max_objs; i++) {
     int index = (i + start) % max_objs;
@@ -375,7 +377,7 @@ bool RGWGC::going_down()
 
 void RGWGC::start_processor()
 {
-  worker = new GCWorker(cct, this);
+  worker = new GCWorker(this, cct, this);
   worker->create("rgw_gc");
 }
 
@@ -390,15 +392,25 @@ void RGWGC::stop_processor()
   worker = NULL;
 }
 
+unsigned RGWGC::get_subsys() const
+{
+  return dout_subsys;
+}
+
+std::ostream& RGWGC::gen_prefix(std::ostream& out) const
+{
+  return out << "garbage collection: ";
+}
+
 void *RGWGC::GCWorker::entry() {
   do {
     utime_t start = ceph_clock_now();
-    dout(2) << "garbage collection: start" << dendl;
+    ldpp_dout(dpp, 2) << "garbage collection: start" << dendl;
     int r = gc->process(true);
     if (r < 0) {
-      dout(0) << "ERROR: garbage collection process() returned error r=" << r << dendl;
+      ldpp_dout(dpp, 0) << "ERROR: garbage collection process() returned error r=" << r << dendl;
     }
-    dout(2) << "garbage collection: stop" << dendl;
+    ldpp_dout(dpp, 2) << "garbage collection: stop" << dendl;
 
     if (gc->going_down())
       break;

diff --git a/src/rgw/rgw_gc.h b/src/rgw/rgw_gc.h
index e9390e8db6c6a8cc8aa9d1eba445973c6c52a2c3..f8f24e97e5d3baecaa1f0cdb50f843296935d3f1 100644 (file)
--- a/src/rgw/rgw_gc.h
+++ b/src/rgw/rgw_gc.h
@@ -18,7 +18,7 @@
 
 class RGWGCIOManager;
 
-class RGWGC {
+class RGWGC : public DoutPrefixProvider {
   CephContext *cct;
   RGWRados *store;
   int max_objs;
@@ -28,13 +28,14 @@ class RGWGC {
   int tag_index(const string& tag);
 
   class GCWorker : public Thread {
+    const DoutPrefixProvider *dpp;
     CephContext *cct;
     RGWGC *gc;
     Mutex lock;
     Cond cond;
 
   public:
-    GCWorker(CephContext *_cct, RGWGC *_gc) : cct(_cct), gc(_gc), lock("GCWorker") {}
+    GCWorker(const DoutPrefixProvider *_dpp, CephContext *_cct, RGWGC *_gc) : dpp(_dpp), cct(_cct), gc(_gc), lock("GCWorker") {}
     void *entry() override;
     void stop();
   };
@@ -64,6 +65,12 @@ public:
   bool going_down();
   void start_processor();
   void stop_processor();
+
+  CephContext *get_cct() const override { return store->ctx(); }
+  unsigned get_subsys() const;
+
+  std::ostream& gen_prefix(std::ostream& out) const;
+
 };
 
 

diff --git a/src/rgw/rgw_lc.cc b/src/rgw/rgw_lc.cc
index e44cc76de3346f26d2ef70cce92915078c347a5d..d32fc9add8bdf024b7bd9d3e2525ce12f9547b2e 100644 (file)
--- a/src/rgw/rgw_lc.cc
+++ b/src/rgw/rgw_lc.cc
@@ -148,12 +148,12 @@ void *RGWLC::LCWorker::entry() {
   do {
     utime_t start = ceph_clock_now();
     if (should_work(start)) {
-      ldout(cct, 2) << "life cycle: start" << dendl;
+      ldpp_dout(dpp, 2) << "life cycle: start" << dendl;
       int r = lc->process();
       if (r < 0) {
-        ldout(cct, 0) << "ERROR: do life cycle process() returned error r=" << r << dendl;
+        ldpp_dout(dpp, 0) << "ERROR: do life cycle process() returned error r=" << r << dendl;
       }
-      ldout(cct, 2) << "life cycle: stop" << dendl;
+      ldpp_dout(dpp, 2) << "life cycle: stop" << dendl;
     }
     if (lc->going_down())
       break;
@@ -163,7 +163,7 @@ void *RGWLC::LCWorker::entry() {
     utime_t next;
     next.set_from_double(end + secs);
 
-    ldout(cct, 5) << "schedule life cycle next start time: " << rgw_to_asctime(next) << dendl;
+    ldpp_dout(dpp, 5) << "schedule life cycle next start time: " << rgw_to_asctime(next) << dendl;
 
     lock.Lock();
     cond.WaitInterval(lock, utime_t(secs, 0));
@@ -240,7 +240,7 @@ int RGWLC::bucket_lc_prepare(int index)
       pair<string, int > entry(iter->first, lc_uninitial);
       ret = cls_rgw_lc_set_entry(store->lc_pool_ctx, obj_names[index],  entry);
       if (ret < 0) {
-        ldout(cct, 0) << "RGWLC::bucket_lc_prepare() failed to set entry on "
+        ldpp_dout(this, 0) << "RGWLC::bucket_lc_prepare() failed to set entry on "
             << obj_names[index] << dendl;
         return ret;
       }
@@ -324,7 +324,7 @@ int RGWLC::handle_multipart_expiration(RGWRados::Bucket *target, const map<strin
       if (ret < 0) {
           if (ret == (-ENOENT))
             return 0;
-          ldout(cct, 0) << "ERROR: store->list_objects():" <<dendl;
+          ldpp_dout(this, 0) << "ERROR: store->list_objects():" <<dendl;
           return ret;
       }
 
@@ -337,9 +337,9 @@ int RGWLC::handle_multipart_expiration(RGWRados::Bucket *target, const map<strin
           RGWObjectCtx rctx(store);
           ret = abort_multipart_upload(store, cct, &rctx, bucket_info, mp_obj);
           if (ret < 0 && ret != -ERR_NO_SUCH_UPLOAD) {
-            ldout(cct, 0) << "ERROR: abort_multipart_upload failed, ret=" << ret << ", meta:" << obj_iter->key << dendl;
+            ldpp_dout(this, 0) << "ERROR: abort_multipart_upload failed, ret=" << ret << ", meta:" << obj_iter->key << dendl;
           } else if (ret == -ERR_NO_SUCH_UPLOAD) {
-            ldout(cct, 5) << "ERROR: abort_multipart_upload failed, ret=" << ret << ", meta:" << obj_iter->key << dendl;
+            ldpp_dout(this, 5) << "ERROR: abort_multipart_upload failed, ret=" << ret << ", meta:" << obj_iter->key << dendl;
           }
           if (going_down())
             return 0;
@@ -377,13 +377,13 @@ int RGWLC::bucket_lc_process(string& shard_id)
   string bucket_id = result[2];
   int ret = store->get_bucket_info(obj_ctx, bucket_tenant, bucket_name, bucket_info, NULL, &bucket_attrs);
   if (ret < 0) {
-    ldout(cct, 0) << "LC:get_bucket_info for " << bucket_name << " failed" << dendl;
+    ldpp_dout(this, 0) << "LC:get_bucket_info for " << bucket_name << " failed" << dendl;
     return ret;
   }
 
   ret = bucket_info.bucket.bucket_id.compare(bucket_id) ;
   if (ret != 0) {
-    ldout(cct, 0) << "LC:old bucket id found. " << bucket_name << " should be deleted" << dendl;
+    ldpp_dout(this, 0) << "LC:old bucket id found. " << bucket_name << " should be deleted" << dendl;
     return -ENOENT;
   }
 
@@ -398,7 +398,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
   try {
       config.decode(iter);
     } catch (const buffer::error& e) {
-      ldout(cct, 0) << __func__ <<  "() decode life cycle config failed" << dendl;
+      ldpp_dout(this, 0) << __func__ <<  "() decode life cycle config failed" << dendl;
       return -1;
     }
 
@@ -427,7 +427,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
         if (ret < 0) {
           if (ret == (-ENOENT))
             return 0;
-          ldout(cct, 0) << "ERROR: store->list_objects():" <<dendl;
+          ldpp_dout(this, 0) << "ERROR: store->list_objects():" <<dendl;
           return ret;
         }
         
@@ -442,7 +442,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
             int ret = read_obj_tags(store, bucket_info, obj, rctx, tags_bl);
             if (ret < 0) {
               if (ret != -ENODATA)
-                ldout(cct, 5) << "ERROR: read_obj_tags returned r=" << ret << dendl;
+                ldpp_dout(this, 5) << "ERROR: read_obj_tags returned r=" << ret << dendl;
               continue;
             }
             RGWObjTags dest_obj_tags;
@@ -450,7 +450,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
               auto iter = tags_bl.cbegin();
               dest_obj_tags.decode(iter);
             } catch (buffer::error& err) {
-               ldout(cct,0) << "ERROR: caught buffer::error, couldn't decode TagSet" << dendl;
+               ldpp_dout(this,0) << "ERROR: caught buffer::error, couldn't decode TagSet" << dendl;
               return -EIO;
             }
 
@@ -458,7 +458,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
                           dest_obj_tags.get_tags().end(),
                           prefix_iter->second.obj_tags->get_tags().begin(),
                           prefix_iter->second.obj_tags->get_tags().end())){
-              ldout(cct, 20) << __func__ << "() skipping obj " << key << " as tags do not match" << dendl;
+              ldpp_dout(this, 20) << __func__ << "() skipping obj " << key << " as tags do not match" << dendl;
               continue;
             }
           }
@@ -479,14 +479,14 @@ int RGWLC::bucket_lc_process(string& shard_id)
             }
             if (state->mtime != obj_iter->meta.mtime) {
               //Check mtime again to avoid delete a recently update object as much as possible
-              ldout(cct, 20) << __func__ << "() skipping removal: state->mtime " << state->mtime << " obj->mtime " << obj_iter->meta.mtime << dendl;
+              ldpp_dout(this, 20) << __func__ << "() skipping removal: state->mtime " << state->mtime << " obj->mtime " << obj_iter->meta.mtime << dendl;
               continue;
             }
             ret = remove_expired_obj(bucket_info, obj_iter->key, obj_iter->meta.owner, obj_iter->meta.owner_display_name, true);
             if (ret < 0) {
-              ldout(cct, 0) << "ERROR: remove_expired_obj " << dendl;
+              ldpp_dout(this, 0) << "ERROR: remove_expired_obj " << dendl;
             } else {
-              ldout(cct, 2) << "DELETED:" << bucket_name << ":" << key << dendl;
+              ldpp_dout(this, 2) << "DELETED:" << bucket_name << ":" << key << dendl;
             }
 
             if (going_down())
@@ -524,7 +524,7 @@ int RGWLC::bucket_lc_process(string& shard_id)
         if (ret < 0) {
           if (ret == (-ENOENT))
             return 0;
-          ldout(cct, 0) << "ERROR: store->list_objects():" <<dendl;
+          ldpp_dout(this, 0) << "ERROR: store->list_objects():" <<dendl;
           return ret;
         }
 
@@ -590,9 +590,9 @@ int RGWLC::bucket_lc_process(string& shard_id)
             }
             ret = remove_expired_obj(bucket_info, obj_iter->key, obj_iter->meta.owner, obj_iter->meta.owner_display_name, remove_indeed);
             if (ret < 0) {
-              ldout(cct, 0) << "ERROR: remove_expired_obj " << dendl;
+              ldpp_dout(this, 0) << "ERROR: remove_expired_obj " << dendl;
             } else {
-              ldout(cct, 2) << "DELETED:" << bucket_name << ":" << obj_iter->key << dendl;
+              ldpp_dout(this, 2) << "DELETED:" << bucket_name << ":" << obj_iter->key << dendl;
             }
 
             if (going_down())
@@ -619,18 +619,18 @@ int RGWLC::bucket_lc_post(int index, int max_lock_sec, pair<string, int >& entry
   do {
     int ret = l.lock_exclusive(&store->lc_pool_ctx, obj_names[index]);
     if (ret == -EBUSY) { /* already locked by another lc processor */
-      ldout(cct, 0) << "RGWLC::bucket_lc_post() failed to acquire lock on "
+      ldpp_dout(this, 0) << "RGWLC::bucket_lc_post() failed to acquire lock on "
           << obj_names[index] << ", sleep 5, try again" << dendl;
       sleep(5);
       continue;
     }
     if (ret < 0)
       return 0;
-    ldout(cct, 20) << "RGWLC::bucket_lc_post() lock " << obj_names[index] << dendl;
+    ldpp_dout(this, 20) << "RGWLC::bucket_lc_post() lock " << obj_names[index] << dendl;
     if (result ==  -ENOENT) {
       ret = cls_rgw_lc_rm_entry(store->lc_pool_ctx, obj_names[index],  entry);
       if (ret < 0) {
-        ldout(cct, 0) << "RGWLC::bucket_lc_post() failed to remove entry "
+        ldpp_dout(this, 0) << "RGWLC::bucket_lc_post() failed to remove entry "
             << obj_names[index] << dendl;
       }
       goto clean;
@@ -642,12 +642,12 @@ int RGWLC::bucket_lc_post(int index, int max_lock_sec, pair<string, int >& entry
 
     ret = cls_rgw_lc_set_entry(store->lc_pool_ctx, obj_names[index],  entry);
     if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to set entry on "
+      ldpp_dout(this, 0) << "RGWLC::process() failed to set entry on "
           << obj_names[index] << dendl;
     }
 clean:
     l.unlock(&store->lc_pool_ctx, obj_names[index]);
-    ldout(cct, 20) << "RGWLC::bucket_lc_post() unlock " << obj_names[index] << dendl;
+    ldpp_dout(this, 20) << "RGWLC::bucket_lc_post() unlock " << obj_names[index] << dendl;
     return 0;
   } while (true);
 }
@@ -661,7 +661,7 @@ int RGWLC::list_lc_progress(const string& marker, uint32_t max_entries, map<stri
     int ret = cls_rgw_lc_list(store->lc_pool_ctx, obj_names[index], marker, max_entries, entries);
     if (ret < 0) {
       if (ret == -ENOENT) {
-        ldout(cct, 10) << __func__ << "() ignoring unfound lc object="
+        ldpp_dout(this, 10) << __func__ << "() ignoring unfound lc object="
                              << obj_names[index] << dendl;
         continue;
       } else {
@@ -706,7 +706,7 @@ int RGWLC::process(int index, int max_lock_secs)
 
     int ret = l.lock_exclusive(&store->lc_pool_ctx, obj_names[index]);
     if (ret == -EBUSY) { /* already locked by another lc processor */
-      ldout(cct, 0) << "RGWLC::process() failed to acquire lock on "
+      ldpp_dout(this, 0) << "RGWLC::process() failed to acquire lock on "
           << obj_names[index] << ", sleep 5, try again" << dendl;
       sleep(5);
       continue;
@@ -717,7 +717,7 @@ int RGWLC::process(int index, int max_lock_secs)
     cls_rgw_lc_obj_head head;
     ret = cls_rgw_lc_get_head(store->lc_pool_ctx, obj_names[index], head);
     if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to get obj head "
+      ldpp_dout(this, 0) << "RGWLC::process() failed to get obj head "
           << obj_names[index] << ", ret=" << ret << dendl;
       goto exit;
     }
@@ -727,7 +727,7 @@ int RGWLC::process(int index, int max_lock_secs)
       head.marker.clear();
       ret = bucket_lc_prepare(index);
       if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to update lc object "
+      ldpp_dout(this, 0) << "RGWLC::process() failed to update lc object "
           << obj_names[index] << ", ret=" << ret << dendl;
       goto exit;
       }
@@ -735,7 +735,7 @@ int RGWLC::process(int index, int max_lock_secs)
 
     ret = cls_rgw_lc_get_next_entry(store->lc_pool_ctx, obj_names[index], head.marker, entry);
     if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to get obj entry "
+      ldpp_dout(this, 0) << "RGWLC::process() failed to get obj entry "
           << obj_names[index] << dendl;
       goto exit;
     }
@@ -746,7 +746,7 @@ int RGWLC::process(int index, int max_lock_secs)
     entry.second = lc_processing;
     ret = cls_rgw_lc_set_entry(store->lc_pool_ctx, obj_names[index],  entry);
     if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to set obj entry " << obj_names[index]
+      ldpp_dout(this, 0) << "RGWLC::process() failed to set obj entry " << obj_names[index]
           << " (" << entry.first << "," << entry.second << ")" << dendl;
       goto exit;
     }
@@ -754,7 +754,7 @@ int RGWLC::process(int index, int max_lock_secs)
     head.marker = entry.first;
     ret = cls_rgw_lc_put_head(store->lc_pool_ctx, obj_names[index],  head);
     if (ret < 0) {
-      ldout(cct, 0) << "RGWLC::process() failed to put head " << obj_names[index] << dendl;
+      ldpp_dout(this, 0) << "RGWLC::process() failed to put head " << obj_names[index] << dendl;
       goto exit;
     }
     l.unlock(&store->lc_pool_ctx, obj_names[index]);
@@ -769,7 +769,7 @@ exit:
 
 void RGWLC::start_processor()
 {
-  worker = new LCWorker(cct, this);
+  worker = new LCWorker(this, cct, this);
   worker->create("lifecycle_thr");
 }
 
@@ -784,6 +784,17 @@ void RGWLC::stop_processor()
   worker = NULL;
 }
 
+
+unsigned RGWLC::get_subsys() const
+{
+  return dout_subsys;
+}
+
+std::ostream& RGWLC::gen_prefix(std::ostream& out) const
+{
+  return out << "lifecycle: ";
+}
+
 void RGWLC::LCWorker::stop()
 {
   Mutex::Locker l(lock);

diff --git a/src/rgw/rgw_lc.h b/src/rgw/rgw_lc.h
index a26862ac9e171b819bafe9538693cabe1e31db9a..21a00e5b7f69d4d05b50dfd93a2d51de17e5880e 100644 (file)
--- a/src/rgw/rgw_lc.h
+++ b/src/rgw/rgw_lc.h
@@ -336,7 +336,7 @@ public:
 };
 WRITE_CLASS_ENCODER(RGWLifecycleConfiguration)
 
-class RGWLC {
+class RGWLC : public DoutPrefixProvider {
   CephContext *cct;
   RGWRados *store;
   int max_objs{0};
@@ -345,13 +345,14 @@ class RGWLC {
   string cookie;
 
   class LCWorker : public Thread {
+    const DoutPrefixProvider *dpp;
     CephContext *cct;
     RGWLC *lc;
     Mutex lock;
     Cond cond;
 
   public:
-    LCWorker(CephContext *_cct, RGWLC *_lc) : cct(_cct), lc(_lc), lock("LCWorker") {}
+    LCWorker(const DoutPrefixProvider* _dpp, CephContext *_cct, RGWLC *_lc) : dpp(_dpp), cct(_cct), lc(_lc), lock("LCWorker") {}
     void *entry() override;
     void stop();
     bool should_work(utime_t& now);
@@ -380,6 +381,10 @@ class RGWLC {
   void start_processor();
   void stop_processor();
 
+  CephContext *get_cct() const override { return store->ctx(); }
+  unsigned get_subsys() const;
+  std::ostream& gen_prefix(std::ostream& out) const;
+
   private:
   int remove_expired_obj(RGWBucketInfo& bucket_info, rgw_obj_key obj_key, const string& owner, const string& owner_display_name, bool remove_indeed = true);
   bool obj_has_expired(ceph::real_time mtime, int days);