common: make command-line programs log to stderr

command-line programs (as opposed to daemons) should send their logs to
stderr rather than to a log file, syslog, etc. This is especially
important because most users want to run the ceph command-line programs
as non-root, and often only root has permissions to add to the ceph
log directory.

Create a new function, set_foreground_logging, that overrides ceph.conf
settings to force all log output to stderr. For daemons, we still only
send the very highest priority messages to stderr, and only before they
daemonize().

Don't ever log to stdout because it interferes with scripts that parse
the output of stdout. Instead, log to stderr if the user gives the
--foreground or --nodaemon argument.

Signed-off-by: Colin McCabe <colinm@hq.newdream.net>

src/cauthtool.cc

@@ -37,6 +37,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "cauthtool", false);
+  set_foreground_logging();
 
   const char *me = argv[0];
 

src/cconf.cc

@@ -172,6 +172,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(nargs, type, false);
+  set_foreground_logging();
 
   if ((nargs.size() == 1) && (!strcmp(nargs[0], "-h"))) {
     usage();

src/common/DoutStreambuf.cc

@@ -253,8 +253,7 @@ DoutStreambuf<charT, traits>::overflow(DoutStreambuf<charT, traits>::int_type c)
 	flags &= ~DOUTSB_FLAG_STDOUT;
     }
     if (flags & DOUTSB_FLAG_STDERR) {
-      // Only write to stderr if the message is important enough.
-      if (prio_is_visible_on_stderr(prio)) {
+      if ((flags & DOUTSB_FLAG_STDERR_ALL) || (prio == -1)) {
 	if (safe_write(STDERR_FILENO, start, len))
 	  flags &= ~DOUTSB_FLAG_STDERR;
       }
@@ -283,13 +282,6 @@ void DoutStreambuf<charT, traits>::handle_stderr_closed()
   flags &= ~DOUTSB_FLAG_STDERR;
 }
 
-template <typename charT, typename traits>
-void DoutStreambuf<charT, traits>::handle_stdout_closed()
-{
-  assert(_dout_lock.is_locked());
-  flags &= ~DOUTSB_FLAG_STDOUT;
-}
-
 template <typename charT, typename traits>
 void DoutStreambuf<charT, traits>::read_global_config()
 {
@@ -305,15 +297,21 @@ void DoutStreambuf<charT, traits>::read_global_config()
     flags |= DOUTSB_FLAG_SYSLOG;
   }
 
-  if (g_conf.log_to_stdout) {
-    if (fd_is_open(STDOUT_FILENO)) {
-      flags |= DOUTSB_FLAG_STDOUT;
-    }
-  }
-
-  if (g_conf.log_to_stderr) {
-    if (fd_is_open(STDERR_FILENO)) {
-      flags |= DOUTSB_FLAG_STDERR;
+  if ((g_conf.log_to_stderr != LOG_TO_STDERR_NONE) &&
+       fd_is_open(STDERR_FILENO)) {
+    switch (g_conf.log_to_stderr) {
+      case LOG_TO_STDERR_SOME:
+	flags |= DOUTSB_FLAG_STDERR_SOME;
+	break;
+      case LOG_TO_STDERR_ALL:
+	flags |= DOUTSB_FLAG_STDERR_ALL;
+	break;
+      default:
+	ostringstream oss;
+	oss << "DoutStreambuf::read_global_config: can't understand "
+	    << "g_conf.log_to_stderr = " << g_conf.log_to_stderr << "\n";
+	primitive_log(oss.str());
+	break;
     }
   }
 
@@ -413,7 +411,6 @@ std::string DoutStreambuf<charT, traits>::config_to_str() const
 {
   assert(_dout_lock.is_locked());
   ostringstream oss;
-  oss << "g_conf.log_to_stdout = " << g_conf.log_to_stdout << "\n";
   oss << "g_conf.log_to_stderr = " << g_conf.log_to_stderr << "\n";
   oss << "g_conf.log_to_syslog = " << g_conf.log_to_syslog << "\n";
   oss << "g_conf.log_to_file = " << g_conf.log_to_file << "\n";

src/common/DoutStreambuf.h

@@ -30,8 +30,10 @@ public:
   enum dout_streambuf_flags_t {
     DOUTSB_FLAG_SYSLOG =          0x01,
     DOUTSB_FLAG_STDOUT =          0x02,
-    DOUTSB_FLAG_STDERR =          0x04,
-    DOUTSB_FLAG_OFILE =           0x08,
+    DOUTSB_FLAG_STDERR_SOME =     0x04,
+    DOUTSB_FLAG_STDERR_ALL =      0x08,
+    DOUTSB_FLAG_STDERR =          0x0c,
+    DOUTSB_FLAG_OFILE =           0x10,
   };
 
   typedef traits traits_ty;
@@ -50,9 +52,6 @@ public:
   // for the error to happen.
   void handle_stderr_closed();
 
-  // Call when you close stdout.
-  void handle_stdout_closed();
-
   // Set the flags based on the global configuration
   void read_global_config();
 

src/common/common_init.cc

@@ -19,6 +19,40 @@
 #include "include/color.h"
 #include "tls.h"
 
+/* Set foreground logging
+ *
+ * Forces the process to log only to stderr, overriding whatever was in the ceph.conf.
+ *
+ * TODO: make this configurable by a command line switch or environment variable, if users want
+ * an unusual logging setup for their foreground process.
+ */
+void set_foreground_logging()
+{
+  free((void*)g_conf.log_file);
+  g_conf.log_file = NULL;
+
+  free((void*)g_conf.log_dir);
+  g_conf.log_dir = NULL;
+
+  free((void*)g_conf.log_sym_dir);
+  g_conf.log_sym_dir = NULL;
+
+  g_conf.log_sym_history = 0;
+
+  g_conf.log_to_stderr = LOG_TO_STDERR_ALL;
+
+  g_conf.log_to_syslog = false;
+
+  g_conf.log_per_instance = false;
+
+  g_conf.log_to_file = false;
+
+  if (_dout_need_open) {
+    Mutex::Locker l(_dout_lock);
+    _dout_open_log(false);
+  }
+}
+
 void common_set_defaults(bool daemon)
 {
   if (daemon) {

src/common/common_init.h

@@ -7,5 +7,6 @@ void common_set_defaults(bool daemon);
 void common_init(std::vector<const char*>& args,
 		 const char *module_type,
                  bool init_keys);
+void set_foreground_logging();
 
 #endif

src/common/debug.cc

@@ -17,7 +17,7 @@ Mutex _dout_lock("_dout_lock", false, false /* no lockdep */);
 #define _STR(x) #x
 #define STRINGIFY(x) _STR(x)
 
-void _dout_open_log()
+void _dout_open_log(bool print_version)
 {
   assert(_dout_need_open);
   assert(_dout_lock.is_locked());
@@ -30,8 +30,10 @@ void _dout_open_log()
     _dout = new std::ostream(_doss);
   }
 
-  *_dout << "ceph version " << VERSION << " (commit:"
-	 << STRINGIFY(CEPH_GIT_VER) << ")" << std::endl;
+  if (print_version) {
+    *_dout << "ceph version " << VERSION << " (commit:"
+	   << STRINGIFY(CEPH_GIT_VER) << ")" << std::endl;
+  }
   _dout_need_open = false;
 }
 
@@ -40,10 +42,9 @@ int dout_handle_daemonize()
   Mutex::Locker l(_dout_lock);
 
   if (_dout_need_open)
-       _dout_open_log();
+       _dout_open_log(true);
 
   assert(_doss);
-  _doss->handle_stdout_closed();
   _doss->handle_stderr_closed();
   return _doss->handle_pid_change();
 }

src/common/debug.h

@@ -29,7 +29,7 @@ extern DoutStreambuf <char> *_doss;
 extern bool _dout_need_open;
 extern Mutex _dout_lock;
 
-extern void _dout_open_log();
+extern void _dout_open_log(bool print_version);
 
 extern int dout_handle_daemonize();
 
@@ -37,7 +37,7 @@ extern int dout_create_rank_symlink(int n);
 
 static inline void _dout_begin_line(signed int prio) {
   if (unlikely(_dout_need_open))
-    _dout_open_log();
+    _dout_open_log(true);
 
   // Put priority information into dout
   _doss->sputc(1);

src/config.cc

@@ -21,6 +21,7 @@
 #include "common/DoutStreambuf.h"
 #include "common/Logger.h"
 #include "common/BackTrace.h"
+#include "common/common_init.h"
 
 #include <fstream>
 #include <stdlib.h>
@@ -328,6 +329,7 @@ static struct config_option config_optionsp[] = {
 	OPTION(log_dir, 0, OPT_STR, "/var/log/ceph"),
 	OPTION(log_sym_dir, 0, OPT_STR, 0),
 	OPTION(log_sym_history, 0, OPT_INT, 10),
+	OPTION(log_to_stderr, 0, OPT_INT, LOG_TO_STDERR_SOME),
 	OPTION(log_to_syslog, 0, OPT_BOOL, false),
 	OPTION(log_per_instance, 0, OPT_BOOL, false),
 	OPTION(log_to_file, 0, OPT_BOOL, true),
@@ -1133,15 +1135,13 @@ void parse_startup_config_options(std::vector<const char*>& args, const char *mo
   std::vector<const char *> nargs;
   bool conf_specified = false;
 
-  g_conf.log_to_stdout = false;
-  g_conf.log_to_stderr = true;
-
   if (!g_conf.id)
     g_conf.id = (char *)g_default_id;
   if (!g_conf.type)
     g_conf.type = (char *)"";
 
   bool isdaemon = g_conf.daemonize;
+  bool force_foreground_logging = false;
 
   FOR_EACH_ARG(args) {
     if (CONF_ARG_EQ("version", 'v')) {
@@ -1158,10 +1158,10 @@ void parse_startup_config_options(std::vector<const char*>& args, const char *mo
       g_conf.public_addr.parse(args[++i]);
     } else if (CONF_ARG_EQ("nodaemon", 'D')) {
       g_conf.daemonize = false;
-      g_conf.log_to_stdout = true;
-      g_conf.log_to_stderr = false;
+      force_foreground_logging = true;
     } else if (CONF_ARG_EQ("foreground", 'f')) {
       g_conf.daemonize = false;
+      force_foreground_logging = true;
     } else if (isdaemon && (CONF_ARG_EQ("id", 'i') || CONF_ARG_EQ("name", 'n'))) {
       CONF_SAFE_SET_ARG_VAL(&g_conf.id, OPT_STR);
     } else if (!isdaemon && (CONF_ARG_EQ("id", 'I') || CONF_ARG_EQ("name", 'n'))) {
@@ -1234,6 +1234,10 @@ void parse_startup_config_options(std::vector<const char*>& args, const char *mo
     exit(1);
   }
 
+  if (force_foreground_logging) {
+    set_foreground_logging();
+  }
+
   if (!cf)
     return;
 

src/config.h

@@ -42,6 +42,12 @@ extern void ceph_set_default_id(const char *id);
 
 struct EntityName;
 
+enum log_to_stderr_t {
+  LOG_TO_STDERR_NONE = 0,
+  LOG_TO_STDERR_SOME = 1,
+  LOG_TO_STDERR_ALL = 2,
+};
+
 struct md_config_t {
   char *type;
   char *id;
@@ -82,8 +88,8 @@ struct md_config_t {
   const char *log_sym_dir;
   int log_sym_history;
 
-  bool log_to_stdout;
-  bool log_to_stderr;
+  int log_to_stderr;
+
   bool log_to_syslog;
   bool log_per_instance;
   bool log_to_file;

src/crushtool.cc

@@ -21,6 +21,7 @@
 
 #include "config.h"
 
+#include "common/common_init.h"
 #include "crush/CrushWrapper.h"
 #include "crush/grammar.h"
 
@@ -773,6 +774,7 @@ struct layer_t {
 
 int main(int argc, const char **argv)
 {
+  set_foreground_logging();
 
   vector<const char*> args;
   argv_to_vec(argc, argv, args);

src/csyn.cc

@@ -45,6 +45,7 @@ int main(int argc, const char **argv, char *envp[])
 
   common_set_defaults(false);
   common_init(args, "csyn", true);
+  set_foreground_logging();
 
   parse_syn_options(args);   // for SyntheticClient
 

src/dumpjournal.cc

@@ -82,6 +82,7 @@ int main(int argc, const char **argv, const char *envp[])
 
   common_set_defaults(false);
   common_init(args, "dumpjournal", false);
+  set_foreground_logging();
 
   vec_to_argv(args, argc, argv);
 

src/dupstore.cc

@@ -89,6 +89,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "dumpstore", false);
+  set_foreground_logging();
 
   // args
   if (args.size() != 4) 

src/fakefuse.cc

@@ -72,6 +72,7 @@ int main(int argc, const char **argv) {
 
   common_set_defaults(false);
   common_init(args, "fakefuse", false);
+  set_foreground_logging();
 
   // start messenger thread
   fakemessenger_startthread();

src/fakesyn.cc

@@ -68,6 +68,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "fakesyn");
+  set_foreground_logging();
 
   int start = 0;
 

src/osdmaptool.cc

@@ -50,6 +50,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "osdmaptool", false);
+  set_foreground_logging();
 
   const char *me = argv[0];
 

src/rados.cc

@@ -94,6 +94,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "rados", true);
+  set_foreground_logging();
 
   vector<const char*> nargs;
   bufferlist indata, outdata;

src/rbd.cc

@@ -1115,6 +1115,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "rbd", true);
+  set_foreground_logging();
 
   const char *poolname = NULL;
   uint64_t size = 0;

src/rgw/rgw_admin.cc

@@ -84,6 +84,7 @@ int main(int argc, char **argv)
 
   common_set_defaults(false);
   common_init(args, "rgw", true);
+  set_foreground_logging();
 
   const char *user_id = 0;
   const char *secret_key = 0;

src/streamtest.cc

@@ -98,6 +98,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, NULL, true);
+  set_foreground_logging();
 
   // args
   if (args.size() < 3) return -1;

src/test/TestDoutStreambuf.cc

@@ -38,14 +38,12 @@ int main(int argc, const char **argv)
   ceph_set_default_id("admin");
   common_set_defaults(false);
   common_init(args, "ceph", true);
+  set_foreground_logging();
 
   DoutStreambuf<char> *dos = new DoutStreambuf<char>();
 
   _dout_lock.Lock();
   dos->read_global_config();
-//  dos->set_flags(DoutStreambuf<char>::DOUTSB_FLAG_SYSLOG |
-//                 DoutStreambuf<char>::DOUTSB_FLAG_STDOUT |
-//		 DoutStreambuf<char>::DOUTSB_FLAG_STDERR);
   _dout_lock.Unlock();
   derr << "using configuration: " << dos->config_to_str() << dendl;
 

src/test/TestEncoding.cc

@@ -96,6 +96,7 @@ int main(int argc, const char **argv)
   ceph_set_default_id("admin");
   common_set_defaults(false);
   common_init(args, "ceph", true);
+  set_foreground_logging();
 
   ret = test_string_sz("I am the very model of a modern major general");
   if (ret)

src/test/TestSignalHandlers.cc

@@ -93,10 +93,10 @@ int main(int argc, const char **argv)
   argv_to_vec(argc, argv, args);
   env_to_vec(args);
   ceph_set_default_id("admin");
+
   common_set_defaults(false);
-  g_conf.log_to_file = true;
-  g_conf.log_file = tmp_log_file.c_str();
   common_init(args, "TestSignalHandlers", true);
+  set_foreground_logging();
 
   DEFINE_CONF_VARS(usage);
   FOR_EACH_ARG(args) {

src/test/TestTimers.cc

@@ -257,6 +257,7 @@ int main(int argc, const char **argv)
   ceph_set_default_id("admin");
   common_set_defaults(false);
   common_init(args, "ceph", true);
+  set_foreground_logging();
 
   int ret;
   Mutex safe_timer_lock("safe_timer_lock");

src/test_trans.cc

@@ -37,6 +37,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, NULL, false);
+  set_foreground_logging();
 
   // args
   if (args.size() < 2) return -1;

src/testmsgr.cc

@@ -71,6 +71,7 @@ int main(int argc, const char **argv, const char *envp[]) {
 
   common_set_defaults(false);
   common_init(args, NULL, false);
+  set_foreground_logging();
 
   vec_to_argv(args, argc, argv);
 

src/tools/ceph.cc

@@ -133,6 +133,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "ceph", true);
+  set_foreground_logging();
 
   vec_to_argv(args, argc, argv);
 

src/tools/gceph.cc

@@ -78,6 +78,7 @@ int main(int argc, const char **argv)
 
   common_set_defaults(false);
   common_init(args, "cephtool", true);
+  set_foreground_logging();
 
   vec_to_argv(args, argc, argv);