diff --git a/src/bin/common/pgsql.c b/src/bin/common/pgsql.c index fe36847f4..bee978c2e 100644 --- a/src/bin/common/pgsql.c +++ b/src/bin/common/pgsql.c @@ -566,7 +566,7 @@ pgsql_open_connection(PGSQL *pgsql) log_error("Failed to connect to %s database at \"%s\", " "see above for details", ConnectionTypeToString(pgsql->connectionType), - pgsql->connectionString); + scrubbedConnectionString); pgsql->status = PG_CONNECTION_BAD; @@ -2471,7 +2471,12 @@ hostname_from_uri(const char *pguri, conninfo = PQconninfoParse(pguri, &errmsg); if (conninfo == NULL) { - log_error("Failed to parse pguri \"%s\": %s", pguri, errmsg); + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + (void) parse_and_scrub_connection_string(pguri, scrubbedConnectionString); + + log_error("Failed to parse pguri \"%s\": %s", + scrubbedConnectionString, errmsg); PQfreemem(errmsg); return false; } @@ -2542,17 +2547,24 @@ validate_connection_string(const char *connectionString) int length = strlen(connectionString); if (length >= MAXCONNINFO) { - log_error("Connection string \"%s\" is %d " + /* don't print the connection string here: it may be too long for + * scrubbing to safely handle, and might still contain a password */ + log_error("Connection string is %d " "characters, the maximum supported by pg_autoctl is %d", - connectionString, length, MAXCONNINFO); + length, MAXCONNINFO); return false; } PQconninfoOption *connInfo = PQconninfoParse(connectionString, &errorMessage); if (connInfo == NULL) { + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + (void) parse_and_scrub_connection_string(connectionString, + scrubbedConnectionString); + log_error("Failed to parse connection string \"%s\": %s ", - connectionString, errorMessage); + scrubbedConnectionString, errorMessage); PQfreemem(errorMessage); return false; } diff --git a/src/bin/pg_autoctl/cli_accept.c b/src/bin/pg_autoctl/cli_accept.c index 7c4fcb506..dfd8e26f3 100644 --- a/src/bin/pg_autoctl/cli_accept.c +++ b/src/bin/pg_autoctl/cli_accept.c @@ -214,7 +214,7 @@ cli_accept_timeline_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } bzero((void *) options.pgSetup.pgdata, sizeof(options.pgSetup.pgdata)); diff --git a/src/bin/pg_autoctl/cli_common.c b/src/bin/pg_autoctl/cli_common.c index 9c819fad3..915d5ab08 100644 --- a/src/bin/pg_autoctl/cli_common.c +++ b/src/bin/pg_autoctl/cli_common.c @@ -2119,7 +2119,7 @@ cli_get_name_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); /* the rest of the program needs pgdata actually empty */ bzero((void *) options.pgSetup.pgdata, @@ -2145,6 +2145,28 @@ cli_get_name_getopts(int argc, char **argv) } +/* + * log_connecting_to_monitor logs an INFO message about connecting to the + * given monitor URI, with any embedded password replaced by **** (see #1043 + * -- the monitor URI carries the autoctl_node password in clear text, and + * this used to get logged as-is). + */ +void +log_connecting_to_monitor(const char *monitorURI) +{ + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + if (parse_and_scrub_connection_string(monitorURI, scrubbedConnectionString)) + { + log_info("Connecting to monitor at \"%s\"", scrubbedConnectionString); + } + else + { + log_info("Connecting to monitor"); + } +} + + /* * cli_use_monitor_option returns true when the --monitor option should be * used, or when PG_AUTOCTL_MONITOR has been set in the environment. In that diff --git a/src/bin/pg_autoctl/cli_common.h b/src/bin/pg_autoctl/cli_common.h index b18d8f7b1..dce65b2a6 100644 --- a/src/bin/pg_autoctl/cli_common.h +++ b/src/bin/pg_autoctl/cli_common.h @@ -216,6 +216,7 @@ bool cli_pg_autoctl_reload(const char *pidfile); int cli_node_metadata_getopts(int argc, char **argv); int cli_get_name_getopts(int argc, char **argv); +void log_connecting_to_monitor(const char *monitorURI); bool cli_use_monitor_option(KeeperConfig *options); void cli_monitor_init_from_option_or_config(Monitor *monitor, KeeperConfig *kconfig); diff --git a/src/bin/pg_autoctl/cli_config.c b/src/bin/pg_autoctl/cli_config.c index dfb867764..cf71b534a 100644 --- a/src/bin/pg_autoctl/cli_config.c +++ b/src/bin/pg_autoctl/cli_config.c @@ -22,6 +22,7 @@ #include "keeper.h" #include "monitor.h" #include "monitor_config.h" +#include "parsing.h" #include "pidfile.h" @@ -366,7 +367,15 @@ cli_config_check_connections(PostgresSetup *pgSetup, /* disconnect from the monitor now */ pgsql_finish(&(monitor.pgsql)); - log_info("Connection to monitor ok, using \"%s\"", monitor_pguri); + { + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + (void) parse_and_scrub_connection_string(monitor_pguri, + scrubbedConnectionString); + + log_info("Connection to monitor ok, using \"%s\"", + scrubbedConnectionString); + } if (strcmp(version.installedVersion, PG_AUTOCTL_EXTENSION_VERSION) == 0) { diff --git a/src/bin/pg_autoctl/cli_drop_node.c b/src/bin/pg_autoctl/cli_drop_node.c index 5972c782d..c14c49463 100644 --- a/src/bin/pg_autoctl/cli_drop_node.c +++ b/src/bin/pg_autoctl/cli_drop_node.c @@ -290,7 +290,7 @@ cli_drop_node_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); /* the rest of the program needs pgdata actually empty */ bzero((void *) options.pgSetup.pgdata, diff --git a/src/bin/pg_autoctl/cli_formation.c b/src/bin/pg_autoctl/cli_formation.c index b06af3bff..42e2c6855 100644 --- a/src/bin/pg_autoctl/cli_formation.c +++ b/src/bin/pg_autoctl/cli_formation.c @@ -230,7 +230,7 @@ keeper_cli_formation_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); /* the rest of the program needs pgdata actually empty */ bzero((void *) options.pgSetup.pgdata, @@ -425,7 +425,7 @@ keeper_cli_formation_create_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); /* the rest of the program needs pgdata actually empty */ bzero((void *) options.pgSetup.pgdata, diff --git a/src/bin/pg_autoctl/cli_node.c b/src/bin/pg_autoctl/cli_node.c index e955eb653..bf793c1e3 100644 --- a/src/bin/pg_autoctl/cli_node.c +++ b/src/bin/pg_autoctl/cli_node.c @@ -29,6 +29,7 @@ #include "log.h" #include "monitor_config.h" #include "nodespec.h" +#include "parsing.h" #include "pgsetup.h" #include "runprogram.h" #include "string_utils.h" @@ -297,7 +298,11 @@ node_copy_ssl_certs(const NodeSpec *spec) /* - * log_argv prints an argv[] to the log, masking password arguments. + * log_argv prints an argv[] to the log, masking password arguments. The + * --monitor argument is a full connection string rather than a bare + * password, so it's scrubbed (password replaced by ****) rather than + * blanked outright, to keep the rest of the URI visible for context (see + * #1043). */ static void log_argv(const char *prefix, char **args, int nargs) @@ -329,7 +334,29 @@ log_argv(const char *prefix, char **args, int nargs) } } } - appendPQExpBufferStr(cmd, maskThis ? "****" : args[i]); + + if (maskThis) + { + appendPQExpBufferStr(cmd, "****"); + } + else if (i > 0 && strcmp(args[i - 1], "--monitor") == 0) + { + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + if (parse_and_scrub_connection_string(args[i], + scrubbedConnectionString)) + { + appendPQExpBufferStr(cmd, scrubbedConnectionString); + } + else + { + appendPQExpBufferStr(cmd, "****"); + } + } + else + { + appendPQExpBufferStr(cmd, args[i]); + } } log_info("%s: %s", prefix, cmd->data); destroyPQExpBuffer(cmd); @@ -706,37 +733,7 @@ cli_node_init(int argc, char **argv) } /* Log the command (masking passwords). */ - { - PQExpBuffer cmd = createPQExpBuffer(); - static const char *pwFlags[] = { - "--monitor-password", - "--replication-password", - "--autoctl-node-password", - NULL - }; - for (int i = 0; i < nargs; i++) - { - if (i > 0) - { - appendPQExpBufferChar(cmd, ' '); - } - bool maskThis = false; - if (i > 0) - { - for (int k = 0; pwFlags[k]; k++) - { - if (strcmp(args[i - 1], pwFlags[k]) == 0) - { - maskThis = true; - break; - } - } - } - appendPQExpBufferStr(cmd, maskThis ? "****" : args[i]); - } - log_info("pg_autoctl node init: %s", cmd->data); - destroyPQExpBuffer(cmd); - } + log_argv("pg_autoctl node init", args, nargs); execv(args[0], args); diff --git a/src/bin/pg_autoctl/cli_perform.c b/src/bin/pg_autoctl/cli_perform.c index b17ddc8ed..3939ea8d3 100644 --- a/src/bin/pg_autoctl/cli_perform.c +++ b/src/bin/pg_autoctl/cli_perform.c @@ -246,7 +246,7 @@ cli_perform_failover_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } /* the rest of the program needs pgdata actually empty */ @@ -545,7 +545,7 @@ cli_perform_promotion_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); /* the rest of the program needs pgdata actually empty */ bzero((void *) options.pgSetup.pgdata, diff --git a/src/bin/pg_autoctl/cli_show.c b/src/bin/pg_autoctl/cli_show.c index 3821cb07c..4db00956b 100644 --- a/src/bin/pg_autoctl/cli_show.c +++ b/src/bin/pg_autoctl/cli_show.c @@ -380,7 +380,7 @@ cli_show_state_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } } else @@ -843,7 +843,7 @@ cli_show_standby_names_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } } else @@ -1066,7 +1066,7 @@ cli_show_timeline_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } } else @@ -1269,7 +1269,7 @@ cli_show_uri_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } } else diff --git a/src/bin/pg_autoctl/cli_watch.c b/src/bin/pg_autoctl/cli_watch.c index bc6ac5bfa..e58502722 100644 --- a/src/bin/pg_autoctl/cli_watch.c +++ b/src/bin/pg_autoctl/cli_watch.c @@ -205,7 +205,7 @@ cli_watch_getopts(int argc, char **argv) if (!IS_EMPTY_STRING_BUFFER(options.pgSetup.pgdata)) { log_warn("Given --monitor URI, the --pgdata option is ignored"); - log_info("Connecting to monitor at \"%s\"", options.monitor_pguri); + log_connecting_to_monitor(options.monitor_pguri); } } else diff --git a/src/bin/pg_autoctl/keeper_config.c b/src/bin/pg_autoctl/keeper_config.c index 23815d28d..7621ff530 100644 --- a/src/bin/pg_autoctl/keeper_config.c +++ b/src/bin/pg_autoctl/keeper_config.c @@ -636,7 +636,14 @@ keeper_config_to_json(KeeperConfig *config, JSON_Value *js) void keeper_config_log_settings(KeeperConfig config) { - log_debug("pg_autoctl.monitor: %s", config.monitor_pguri); + { + char scrubbedConnectionString[MAXCONNINFO] = { 0 }; + + (void) parse_and_scrub_connection_string(config.monitor_pguri, + scrubbedConnectionString); + + log_debug("pg_autoctl.monitor: %s", scrubbedConnectionString); + } log_debug("pg_autoctl.formation: %s", config.formation); log_debug("postgresql.hostname: %s", config.hostname); diff --git a/tests/tap/specs/auth.pgaf b/tests/tap/specs/auth.pgaf index 3a99689fb..c7e52aa4a 100644 --- a/tests/tap/specs/auth.pgaf +++ b/tests/tap/specs/auth.pgaf @@ -75,3 +75,16 @@ step test_005_logging_of_passwords { logs node2 contains "monitor-password ****" logs node2 contains "replication-password ****" } + +step test_006_no_password_leak_on_monitor_disconnect { + # node1 (secondary) cannot reach the monitor while cut off from the + # network: its node-active loop keeps retrying node_active() and hitting + # the "Failed to connect to monitor database" error path (see #1043). + network disconnect node1 + sleep 5s + logs node1 contains "Failed to connect to monitor database" + logs node1 contains "****" + logs node1 not contains "pg-auto-failover" + network connect node1 + wait until node1 state is secondary timeout 90s +}