From 8ab1901a93708d58e0530564912135d7e6021ded Mon Sep 17 00:00:00 2001 From: Ian Barwick Date: Mon, 16 Nov 2015 13:06:32 +0900 Subject: [PATCH] Repurpose -v/--verbose; add -t/--terse option (repmgr only) repmgr and particularly repmgrd currently produce substantial amounts of log output. Much of this is only useful when troubleshooting or debugging. Previously the -v/--verbose option just forced the log level to INFO. With repmgrd this is pretty pointless - just set the log level in the configuration file. With repmgr the configuration file can be overriden by the new -L/--log-level option. -v/--verbose now provides an additional, chattier/pedantic level of logging ("Opening *this* logfile", "Executing *this* query", "running in *this* loop") which is helpful for understanding repmgr/repmgrd's behaviour, particularly for troubleshooting. What additional verbose logging is generated will of course a also depends on the log level set, so e.g. someone trying to work out which configuration file is actually being opened can use '--log-level=INFO --verbose' without being bothered by an avalanche of extra verbose debugging output. -t/--terse option will silence certain non-essential output, at the moment any HINTs. Note that -v/--verbose and -t/--terse are not mutually exclusive (suggestions for better names welcome). --- log.c | 72 ++++++++++++++++++++++++++++++++++++++++++++++++------- log.h | 5 +++- repmgr.c | 19 +++++++++++---- repmgrd.c | 17 +++++-------- 4 files changed, 88 insertions(+), 25 deletions(-) diff --git a/log.c b/log.c index 1e89272d..818101dc 100644 --- a/log.c +++ b/log.c @@ -44,6 +44,8 @@ static int detect_log_facility(const char *facility); int log_type = REPMGR_STDERR; int log_level = LOG_NOTICE; int last_log_level = LOG_NOTICE; +int verbose_logging = false; +int terse_logging = false; void stderr_log_with_level(const char *level_name, int level, const char *fmt, ...) @@ -79,12 +81,56 @@ log_hint(const char *fmt, ...) { va_list ap; - va_start(ap, fmt); - stderr_log_with_level("HINT", last_log_level, fmt, ap); - va_end(ap); + if (terse_logging == false) + { + va_start(ap, fmt); + stderr_log_with_level("HINT", last_log_level, fmt, ap); + va_end(ap); + } } +void +log_verbose(int level, const char *fmt, ...) +{ + va_list ap; + + va_start(ap, fmt); + + if (verbose_logging == true) + { + switch(level) + { + case LOG_EMERG: + log_emerg(fmt, ap); + break; + case LOG_ALERT: + log_alert(fmt, ap); + break; + case LOG_CRIT: + log_crit(fmt, ap); + break; + case LOG_ERR: + log_err(fmt, ap); + break; + case LOG_WARNING: + log_warning(fmt, ap); + break; + case LOG_NOTICE: + log_notice(fmt, ap); + break; + case LOG_INFO: + log_info(fmt, ap); + break; + case LOG_DEBUG: + log_debug(fmt, ap); + break; + } + } + + va_end(ap); +} + bool logger_init(t_configuration_options * opts, const char *ident, const char *level, const char *facility) { @@ -205,15 +251,23 @@ logger_shutdown(void) } /* - * Set a minimum logging level. Intended for command line verbosity - * options, which might increase requested logging over what's specified - * in the regular configuration file. + * Indicated whether extra-verbose logging is required. This will + * generate a lot of output, particularly debug logging, and should + * not be permanently enabled in production. + * + * NOTE: in previous repmgr versions, this option forced the log + * level to INFO. */ void -logger_min_verbose(int minimum) +logger_set_verbose(void) { - if (log_level < minimum) - log_level = minimum; + verbose_logging = true; +} + + +void logger_set_terse(void) +{ + terse_logging = true; } int diff --git a/log.h b/log.h index 6a56b240..fa2d2e3b 100644 --- a/log.h +++ b/log.h @@ -121,8 +121,11 @@ bool logger_init(t_configuration_options * opts, const char *ident, bool logger_shutdown(void); -void logger_min_verbose(int minimum); +void logger_set_verbose(void); +void logger_set_terse(void); + void log_hint(const char *fmt, ...); +void log_verbose(int level, const char *fmt, ...); extern int log_type; extern int log_level; diff --git a/repmgr.c b/repmgr.c index 6730277e..4a0ed781 100644 --- a/repmgr.c +++ b/repmgr.c @@ -451,7 +451,7 @@ main(int argc, char **argv) } /* - * If no primary port (-p, --port) provided, explicitly set the + * If no primary port (-p/--port) provided, explicitly set the * default PostgreSQL port. */ if (!runtime_options.masterport[0]) @@ -460,6 +460,13 @@ main(int argc, char **argv) } + /* + * The logger is not yet set up as some configuration can be included + * in the configuration file; however if verbosity requested, we'll + * display the name of the configuration file we're attempting to open + * for the user's convenience as we might be opening the default + * ./repmgr.conf. + */ if (runtime_options.verbose && runtime_options.config_file[0]) { log_notice(_("opening configuration file: %s\n"), @@ -521,7 +528,8 @@ main(int argc, char **argv) logger_init(&options, progname(), options.loglevel, options.logfacility); if (runtime_options.verbose) - logger_min_verbose(LOG_INFO); + logger_set_verbose(); + /* * Node configuration information is not needed for all actions, with @@ -2531,7 +2539,11 @@ help(void) printf(_("General options:\n")); printf(_(" -?, --help show this help, then exit\n")); printf(_(" -V, --version output version information, then exit\n")); - printf(_(" -v, --verbose output verbose activity information\n")); + printf(_("\n")); + printf(_("Logging options:\n")); + printf(_(" -L, --log-level set log level (overrides configuration file)\n")); + printf(_(" -v, --verbose display additional log output (useful for debugging)\n")); + printf(_(" -t, --terse don't display hints and other non-critical output\n")); printf(_("\n")); printf(_("Connection options:\n")); printf(_(" -d, --dbname=DBNAME database to connect to\n")); @@ -2547,7 +2559,6 @@ help(void) printf(_(" -R, --remote-user=USERNAME database server username for rsync\n")); printf(_(" -F, --force force potentially dangerous operations to happen\n")); printf(_(" --check-upstream-config verify upstream server configuration\n")); - printf(_(" -L, --log-level set log level (overrides configuration file)\n")); printf(_("\n")); printf(_("Command-specific configuration options:\n")); printf(_(" -c, --fast-checkpoint (standby clone) force fast checkpoint\n")); diff --git a/repmgrd.c b/repmgrd.c index e274ebe5..7944f1cd 100644 --- a/repmgrd.c +++ b/repmgrd.c @@ -232,7 +232,7 @@ main(int argc, char **argv) logger_init(&local_options, progname(), local_options.loglevel, local_options.logfacility); if (verbose) - logger_min_verbose(LOG_INFO); + logger_set_verbose(); if (log_type == REPMGR_SYSLOG) { @@ -246,6 +246,7 @@ main(int argc, char **argv) } /* Initialise the repmgr schema name */ + /* XXX check this handles quoting properly */ maxlen_snprintf(repmgr_schema, "%s%s", DEFAULT_REPMGR_SCHEMA_PREFIX, local_options.cluster_name); @@ -456,10 +457,7 @@ main(int argc, char **argv) do { - if (verbose) - { - log_debug("standby check loop...\n"); - } + log_verbose(LOG_DEBUG, "standby check loop...\n"); if (node_info.type == WITNESS) { @@ -469,6 +467,7 @@ main(int argc, char **argv) { standby_monitor(); } + sleep(local_options.monitor_interval_secs); if (got_SIGHUP) @@ -1056,10 +1055,7 @@ standby_monitor(void) * Execute the query asynchronously, but don't check for a result. We will * check the result next time we pause for a monitor step. */ - if (verbose) - { - log_debug("standby_monitor:() %s\n", sqlquery); - } + log_verbose(LOG_DEBUG, "standby_monitor:() %s\n", sqlquery); if (PQsendQuery(master_conn, sqlquery) == 0) log_warning(_("query could not be sent to master. %s\n"), @@ -1464,8 +1460,7 @@ do_master_failover(void) /* wait */ sleep(5); - if (verbose) - log_info(_("this node is the best candidate to be the new master, promoting...\n")); + log_notice(_("this node is the best candidate to be the new master, promoting...\n")); log_debug(_("promote command is: \"%s\"\n"), local_options.promote_command);