Merge pull request ceph#21112 from guzhongyan/fix-vlog

src: fix various log messages

Reviewed-by: Kefu Chai <[email protected]>

src/client/Client.cc

@@ -10045,9 +10045,9 @@ int Client::_sync_fs()
 
   if (nullptr != cond) {
     client_lock.Unlock();
-    ldout(cct, 15) << __func__ << "waiting on data to flush" << dendl;
+    ldout(cct, 15) << __func__ << " waiting on data to flush" << dendl;
     cond->wait();
-    ldout(cct, 15) << __func__ << "flush finished" << dendl;
+    ldout(cct, 15) << __func__ << " flush finished" << dendl;
     client_lock.Lock();
   }
 
@@ -10362,7 +10362,7 @@ int Client::ll_walk(const char* name, Inode **out, struct ceph_statx *stx,
   int rc;
   unsigned mask = statx_to_mask(flags, want);
 
-  ldout(cct, 3) << __func__ << name << dendl;
+  ldout(cct, 3) << __func__ << " " << name << dendl;
   tout(cct) << __func__ << std::endl;
   tout(cct) << name << std::endl;
 

src/common/LogClient.cc

@@ -315,7 +315,7 @@ void LogClient::_send_to_mon()
   assert(log_lock.is_locked());
   assert(is_mon);
   assert(messenger->get_myname().is_mon());
-  ldout(cct,10) << __func__ << "log to self" << dendl;
+  ldout(cct,10) << __func__ << " log to self" << dendl;
   Message *log = _get_mon_log_message();
   messenger->get_loopback_connection()->send_message(log);
 }

src/kv/KineticStore.cc

@@ -40,7 +40,7 @@ int KineticStore::_test_init(CephContext *c)
   kinetic::Status status = conn_factory.NewThreadsafeBlockingConnection(options, kinetic_conn, 10);
   kinetic_conn.reset();
   if (!status.ok())
-    derr << __func__ << "Unable to connect to kinetic store " << options.host
+    derr << __func__ << " Unable to connect to kinetic store " << options.host
          << ":" << options.port << " : " << status.ToString() << dendl;
   return status.ok() ? 0 : -EIO;
 }

src/kv/RocksDBStore.cc

@@ -674,7 +674,7 @@ void RocksDBStore::split_stats(const std::string &s, char delim, std::vector<std
 void RocksDBStore::get_statistics(Formatter *f)
 {
   if (!g_conf->rocksdb_perf)  {
-    dout(20) << __func__ << "RocksDB perf is disabled, can't probe for stats"
+    dout(20) << __func__ << " RocksDB perf is disabled, can't probe for stats"
 	     << dendl;
     return;
   }

src/librbd/operation/DisableFeaturesRequest.cc

@@ -53,7 +53,7 @@ template <typename I>
 bool DisableFeaturesRequest<I>::should_complete(int r) {
   I &image_ctx = this->m_image_ctx;
   CephContext *cct = image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << "r=" << r << dendl;
+  ldout(cct, 20) << this << " " << __func__ << " r=" << r << dendl;
 
   if (r < 0) {
     lderr(cct) << "encountered error: " << cpp_strerror(r) << dendl;

src/librbd/operation/EnableFeaturesRequest.cc

@@ -49,7 +49,7 @@ template <typename I>
 bool EnableFeaturesRequest<I>::should_complete(int r) {
   I &image_ctx = this->m_image_ctx;
   CephContext *cct = image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << "r=" << r << dendl;
+  ldout(cct, 20) << this << " " << __func__ << " r=" << r << dendl;
 
   if (r < 0) {
     lderr(cct) << "encountered error: " << cpp_strerror(r) << dendl;

src/librbd/operation/MetadataRemoveRequest.cc

@@ -29,7 +29,7 @@ template <typename I>
 bool MetadataRemoveRequest<I>::should_complete(int r) {
   I &image_ctx = this->m_image_ctx;
   CephContext *cct = image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << "r=" << r << dendl;
+  ldout(cct, 20) << this << " " << __func__ << " r=" << r << dendl;
 
   if (r < 0) {
     lderr(cct) << "encountered error: " << cpp_strerror(r) << dendl;

src/librbd/operation/MetadataSetRequest.cc

@@ -30,7 +30,7 @@ template <typename I>
 bool MetadataSetRequest<I>::should_complete(int r) {
   I &image_ctx = this->m_image_ctx;
   CephContext *cct = image_ctx.cct;
-  ldout(cct, 20) << this << " " << __func__ << "r=" << r << dendl;
+  ldout(cct, 20) << this << " " << __func__ << " r=" << r << dendl;
 
   if (r < 0) {
     lderr(cct) << "encountered error: " << cpp_strerror(r) << dendl;

src/librbd/operation/SnapshotLimitRequest.cc

@@ -29,7 +29,7 @@ template <typename I>
 bool SnapshotLimitRequest<I>::should_complete(int r) {
   I &image_ctx = this->m_image_ctx;
   CephContext *cct = image_ctx.cct;
-  ldout(cct, 5) << this << " " << __func__ << "r=" << r << dendl;
+  ldout(cct, 5) << this << " " << __func__ << " r=" << r << dendl;
 
   if (r < 0) {
     lderr(cct) << "encountered error: " << cpp_strerror(r) << dendl;

src/mds/MDCache.cc

@@ -12249,7 +12249,7 @@ void MDCache::enqueue_scrub(
     bool force, bool recursive, bool repair,
     Formatter *f, Context *fin)
 {
-  dout(10) << __func__ << path << dendl;
+  dout(10) << __func__ << " " << path << dendl;
   MDRequestRef mdr = request_start_internal(CEPH_MDS_OP_ENQUEUE_SCRUB);
   filepath fp(path);
   mdr->set_filepath(fp);

src/mds/ScrubStack.cc

@@ -128,7 +128,7 @@ void ScrubStack::scrub_dir_inode(CInode *in,
                                  bool *terminal,
                                  bool *done)
 {
-  dout(10) << __func__ << *in << dendl;
+  dout(10) << __func__ << " " << *in << dendl;
 
   *added_children = false;
   bool all_frags_terminal = true;
@@ -266,7 +266,7 @@ class C_InodeValidated : public MDSInternalContext
 
 void ScrubStack::scrub_dir_inode_final(CInode *in)
 {
-  dout(20) << __func__ << *in << dendl;
+  dout(20) << __func__ << " " << *in << dendl;
 
   // Two passes through this function.  First one triggers inode validation,
   // second one sets finally_done

src/mgr/ActivePyModules.cc

@@ -420,7 +420,7 @@ bool ActivePyModules::get_config(const std::string &module_name,
   const std::string global_key = PyModuleRegistry::config_prefix
     + module_name + "/" + key;
 
-  dout(4) << __func__ << "key: " << global_key << dendl;
+  dout(4) << __func__ << " key: " << global_key << dendl;
 
   if (config_cache.count(global_key)) {
     *val = config_cache.at(global_key);
@@ -440,7 +440,7 @@ PyObject *ActivePyModules::get_config_prefix(const std::string &module_name,
   const std::string base_prefix = PyModuleRegistry::config_prefix
                                     + module_name + "/";
   const std::string global_prefix = base_prefix + prefix;
-  dout(4) << __func__ << "prefix: " << global_prefix << dendl;
+  dout(4) << __func__ << " prefix: " << global_prefix << dendl;
 
   PyFormatter f;
   for (auto p = config_cache.lower_bound(global_prefix);

src/mgr/StandbyPyModules.cc

@@ -170,7 +170,7 @@ bool StandbyPyModule::get_config(const std::string &key,
   const std::string global_key = PyModuleRegistry::config_prefix
     + get_name() + "/" + key;
 
-  dout(4) << __func__ << "key: " << global_key << dendl;
+  dout(4) << __func__ << " key: " << global_key << dendl;
 
   return state.with_config([global_key, value](const PyModuleConfig &config){
     if (config.count(global_key)) {

src/mon/MonmapMonitor.cc

@@ -672,7 +672,7 @@ bool MonmapMonitor::prepare_command(MonOpRequestRef op)
     pending_map.last_changed = ceph_clock_now();
     propose = true;
 
-    dout(1) << __func__ << ss.str() << "; new features will be: "
+    dout(1) << __func__ << " " << ss.str() << "; new features will be: "
             << "persistent = " << pending_map.persistent_features
             // output optional nevertheless, for auditing purposes.
             << ", optional = " << pending_map.optional_features << dendl;

src/msg/async/AsyncMessenger.cc

@@ -583,7 +583,7 @@ void AsyncMessenger::submit_message(Message *m, AsyncConnectionRef con,
 {
   if (cct->_conf->ms_dump_on_send) {
     m->encode(-1, MSG_CRC_ALL);
-    ldout(cct, 0) << __func__ << "submit_message " << *m << "\n";
+    ldout(cct, 0) << __func__ << " submit_message " << *m << "\n";
     m->get_payload().hexdump(*_dout);
     if (m->get_data().length() > 0) {
       *_dout << " data:\n";

src/msg/async/dpdk/DPDK.cc

@@ -562,7 +562,7 @@ int DPDKDevice::check_port_link_status()
         ldout(cct, 20) << __func__ << " not ready, continue to wait." << dendl;
         usleep(sleep_time);
       } else {
-        lderr(cct) << __func__ << "done port " << _port_idx << " link down" << dendl;
+        lderr(cct) << __func__ << " done port " << _port_idx << " link down" << dendl;
         return -1;
       }
     }

src/msg/async/rdma/Infiniband.cc

@@ -705,14 +705,14 @@ char *Infiniband::MemoryManager::PoolAllocator::malloc(const size_type bytes)
 
   m = static_cast<mem_info *>(manager->malloc(bytes + sizeof(*m)));
   if (!m) {
-    lderr(cct) << __func__ << "failed to allocate " <<
+    lderr(cct) << __func__ << " failed to allocate " <<
         bytes << " + " << sizeof(*m) << " bytes of memory for " << nbufs << dendl;
     return NULL;
   }
 
   m->mr = ibv_reg_mr(manager->pd->pd, m->chunks, bytes, IBV_ACCESS_REMOTE_WRITE | IBV_ACCESS_LOCAL_WRITE);
   if (m->mr == NULL) {
-    lderr(cct) << __func__ << "failed to register " <<
+    lderr(cct) << __func__ << " failed to register " <<
         bytes << " + " << sizeof(*m) << " bytes of memory for " << nbufs << dendl;
     manager->free(m);
     return NULL;

src/msg/simple/Accepter.cc

@@ -383,7 +383,7 @@ void Accepter::stop()
   char ch = 0x0;
   int ret = safe_write(shutdown_wr_fd, &ch, sizeof(ch));
   if (ret < 0) {
-    ldout(msgr->cct,1) << __func__ << "close failed: "
+    ldout(msgr->cct,1) << __func__ << " close failed: "
              << " errno " << errno << " " << cpp_strerror(errno) << dendl;
   } else {
     ldout(msgr->cct,15) << __func__ << " signaled poll" << dendl;
@@ -400,14 +400,14 @@ void Accepter::stop()
 
   if (listen_sd >= 0) {
     if (::close(listen_sd) < 0) {
-      ldout(msgr->cct,1) << __func__ << "close listen_sd failed: "
+      ldout(msgr->cct,1) << __func__ << " close listen_sd failed: "
 	      << " errno " << errno << " " << cpp_strerror(errno) << dendl;
     }
     listen_sd = -1;
   }
   if (shutdown_rd_fd >= 0) {
     if (::close(shutdown_rd_fd) < 0) {
-      ldout(msgr->cct,1) << __func__ << "close shutdown_rd_fd failed: "
+      ldout(msgr->cct,1) << __func__ << " close shutdown_rd_fd failed: "
 	      << " errno " << errno << " " << cpp_strerror(errno) << dendl;
     }
     shutdown_rd_fd = -1;

src/msg/xio/XioMessenger.cc

@@ -866,9 +866,9 @@ int XioMessenger::_send_message_impl(Message* m, XioConnection* xcon)
     switch (m->get_type()) {
     case 43:
     // case 15:
-      ldout(cct,4) << __func__ << "stop 43 " << m->get_type() << " " << *m << dendl;
+      ldout(cct,4) << __func__ << " stop 43 " << m->get_type() << " " << *m << dendl;
       buffer::list &payload = m->get_payload();
-      ldout(cct,4) << __func__ << "payload dump:" << dendl;
+      ldout(cct,4) << __func__ << " payload dump:" << dendl;
       payload.hexdump(cout);
     }
   }

src/os/bluestore/BlueStore.cc

@@ -9855,7 +9855,7 @@ void BlueStore::_txc_add_transaction(TransContext *txc, Transaction *t)
       break;
 
     default:
-      derr << __func__ << "bad op " << op->op << dendl;
+      derr << __func__ << " bad op " << op->op << dendl;
       ceph_abort();
     }
 
@@ -11405,7 +11405,7 @@ void BlueStore::_do_omap_clear(TransContext *txc, const string& omap_prefix,
   get_omap_header(id, &prefix);
   get_omap_tail(id, &tail);
   txc->t->rm_range_keys(omap_prefix, prefix, tail);
-  dout(20) << __func__ << "remove range start: "
+  dout(20) << __func__ << " remove range start: "
            << pretty_binary_string(prefix) << " end: "
            << pretty_binary_string(tail) << dendl;
 }
@@ -11549,7 +11549,7 @@ int BlueStore::_omap_rmkey_range(TransContext *txc,
     get_omap_key(o->onode.nid, first, &key_first);
     get_omap_key(o->onode.nid, last, &key_last);
     txc->t->rm_range_keys(prefix, key_first, key_last);
-    dout(20) << __func__ << "remove range start: "
+    dout(20) << __func__ << " remove range start: "
              << pretty_binary_string(key_first) << " end: "
              << pretty_binary_string(key_last) << dendl;
   }
@@ -12132,7 +12132,7 @@ void BlueStore::_flush_cache()
   }
   for (auto& p : coll_map) {
     if (!p.second->onode_map.empty()) {
-      derr << __func__ << "stray onodes on " << p.first << dendl;
+      derr << __func__ << " stray onodes on " << p.first << dendl;
       p.second->onode_map.dump<0>(cct);
     }
     if (!p.second->shared_blob_set.empty()) {

src/os/filestore/FileJournal.cc

@@ -1749,7 +1749,7 @@ void FileJournal::commit_start(uint64_t seq)
  */
 void FileJournal::do_discard(int64_t offset, int64_t end)
 {
-  dout(10) << __func__ << "trim(" << offset << ", " << end << dendl;
+  dout(10) << __func__ << " trim(" << offset << ", " << end << dendl;
 
   offset = round_up_to(offset, block_size);
   if (offset >= end)
@@ -1758,7 +1758,7 @@ void FileJournal::do_discard(int64_t offset, int64_t end)
   assert(end >= offset);
   if (offset < end)
     if (block_device_discard(fd, offset, end - offset) < 0)
-	dout(1) << __func__ << "ioctl(BLKDISCARD) error:" << cpp_strerror(errno) << dendl;
+	dout(1) << __func__ << " ioctl(BLKDISCARD) error:" << cpp_strerror(errno) << dendl;
 }
 
 void FileJournal::committed_thru(uint64_t seq)

src/osd/PG.cc

@@ -1490,7 +1490,7 @@ bool PG::recoverable_and_ge_min_size(const vector<int> &want) const
   boost::scoped_ptr<IsPGRecoverablePredicate> recoverable_predicate(
       get_pgbackend()->get_is_recoverable_predicate());
   if (!(*recoverable_predicate)(have)) {
-    dout(10) << __func__ << "failed, not recoverable" << dendl;
+    dout(10) << __func__ << " failed, not recoverable" << dendl;
     return false;
   }
 
@@ -5571,7 +5571,7 @@ bool PG::append_log_entries_update_missing(
   }
   info.stats.stats_invalid = info.stats.stats_invalid || invalidate_stats;
 
-  dout(20) << __func__ << "trim_to bool = " << bool(trim_to) << " trim_to = " << (trim_to ? *trim_to : eversion_t()) << dendl;
+  dout(20) << __func__ << " trim_to bool = " << bool(trim_to) << " trim_to = " << (trim_to ? *trim_to : eversion_t()) << dendl;
   if (trim_to)
     pg_log.trim(*trim_to, info);
   dirty_info = true;

src/osd/PrimaryLogPG.cc

@@ -13953,7 +13953,7 @@ bool PrimaryLogPG::agent_choose_mode(bool restart, OpRequestRef op)
   bool requeued = false;
   // Let delay play out
   if (agent_state->delaying) {
-    dout(20) << __func__ << this << " delaying, ignored" << dendl;
+    dout(20) << __func__ << " " << this << " delaying, ignored" << dendl;
     return requeued;
   }
 

src/osdc/Objecter.cc

@@ -3674,7 +3674,7 @@ uint32_t Objecter::list_nobjects_seek(NListContext *list_context,
   shared_lock rl(rwlock);
   list_context->pos = hobject_t(object_t(), string(), CEPH_NOSNAP,
 				pos, list_context->pool_id, string());
-  ldout(cct, 10) << __func__ << list_context
+  ldout(cct, 10) << __func__ << " " << list_context
 		 << " pos " << pos << " -> " << list_context->pos << dendl;
   pg_t actual = osdmap->raw_pg_to_pg(pg_t(pos, list_context->pool_id));
   list_context->current_pg = actual.ps();

src/rgw/rgw_file.cc

@@ -1767,7 +1767,7 @@ int rgw_lookup(struct rgw_fs *rgw_fs,
     if (unlikely((strcmp(path, "..") == 0))) {
       rgw_fh = parent;
       lsubdout(fs->get_context(), rgw, 17)
-	<< __func__ << "BANG"<< *rgw_fh
+	<< __func__ << " BANG"<< *rgw_fh
 	<< dendl;
       fs->ref(rgw_fh);
     } else {

src/rgw/rgw_http_client_curl.cc

@@ -27,15 +27,15 @@ class RGWSSLSetup
     try {
       locks.at(id).lock();
     } catch (std::out_of_range& e) {
-      dout(0) << __func__ << "failed to set locks" << dendl;
+      dout(0) << __func__ << " failed to set locks" << dendl;
     }
   }
 
   void clear_lock(int id){
     try {
       locks.at(id).unlock();
     } catch (std::out_of_range& e) {
-      dout(0) << __func__ << "failed to unlock" << dendl;
+      dout(0) << __func__ << " failed to unlock" << dendl;
     }
   }
 };

src/rgw/rgw_op.cc

@@ -2173,7 +2173,7 @@ void RGWSetBucketVersioning::execute()
   if (!store->is_meta_master()) {
     op_ret = forward_request_to_master(s, NULL, store, in_data, nullptr);
     if (op_ret < 0) {
-      ldout(s->cct, 20) << __func__ << "forward_request_to_master returned ret=" << op_ret << dendl;
+      ldout(s->cct, 20) << __func__ << " forward_request_to_master returned ret=" << op_ret << dendl;
       return;
     }
   }
@@ -4915,7 +4915,7 @@ void RGWPutACLs::execute()
     }
     op_ret = forward_request_to_master(s, NULL, store, in_data, NULL);
     if (op_ret < 0) {
-      ldout(s->cct, 20) << __func__ << "forward_request_to_master returned ret=" << op_ret << dendl;
+      ldout(s->cct, 20) << __func__ << " forward_request_to_master returned ret=" << op_ret << dendl;
       return;
     }
   }
@@ -5152,7 +5152,7 @@ void RGWPutCORS::execute()
   if (!store->is_meta_master()) {
     op_ret = forward_request_to_master(s, NULL, store, in_data, nullptr);
     if (op_ret < 0) {
-      ldout(s->cct, 20) << __func__ << "forward_request_to_master returned ret=" << op_ret << dendl;
+      ldout(s->cct, 20) << __func__ << " forward_request_to_master returned ret=" << op_ret << dendl;
       return;
     }
   }

src/rgw/rgw_rados.cc

@@ -4073,7 +4073,7 @@ int RGWRados::replace_region_with_zonegroup()
   /* create zonegroups */
   for (iter = regions.begin(); iter != regions.end(); ++iter)
   {
-    ldout(cct, 0) << __func__ << "Converting  " << *iter << dendl;
+    ldout(cct, 0) << __func__ << " Converting  " << *iter << dendl;
     /* check to see if we don't have already a zonegroup with this name */
     RGWZoneGroup new_zonegroup(*iter);
     ret = new_zonegroup.init(cct , this);

src/rgw/rgw_rest_s3.cc

@@ -3458,7 +3458,7 @@ int RGWHandler_REST_S3Website::init(RGWRados *store, req_state *s,
 
 int RGWHandler_REST_S3Website::retarget(RGWOp* op, RGWOp** new_op) {
   *new_op = op;
-  ldout(s->cct, 10) << __func__ << "Starting retarget" << dendl;
+  ldout(s->cct, 10) << __func__ << " Starting retarget" << dendl;
 
   if (!(s->prot_flags & RGW_REST_WEBSITE))
     return 0;