commit a506efdaecd6643b54d6c1ae26a98ec525d450ed
Author: Ken Gaillot <kgaillot@redhat.com>
Date:   Wed Oct 25 16:38:36 2017 -0500

    Log: libcrmcommon,liblrmd: improve remote connection messages

diff --git a/lib/common/remote.c b/lib/common/remote.c
index ddeaddc93..05a780606 100644
--- a/lib/common/remote.c
+++ b/lib/common/remote.c
@@ -772,16 +772,15 @@ internal_tcp_connect_async(int sock,
     int timer;
     struct tcp_async_cb_data *cb_data = NULL;
 
-    if ((flag = fcntl(sock, F_GETFL)) >= 0) {
-        if (fcntl(sock, F_SETFL, flag | O_NONBLOCK) < 0) {
-            crm_err("fcntl() write failed");
-            return -1;
-        }
+    flag = fcntl(sock, F_GETFL);
+    if ((flag >= 0) && (fcntl(sock, F_SETFL, flag | O_NONBLOCK) < 0)) {
+        crm_perror(LOG_WARNING, "setting socket non-blocking");
+        return -1;
     }
 
     rc = connect(sock, addr, addrlen);
-
     if (rc < 0 && (errno != EINPROGRESS) && (errno != EAGAIN)) {
+        crm_perror(LOG_WARNING, "connect");
         return -1;
     }
 
@@ -809,7 +808,8 @@ internal_tcp_connect_async(int sock,
      * At some point we should figure out a way to use a mainloop fd callback for this.
      * Something about the way mainloop is currently polling prevents this from working at the
      * moment though. */
-    crm_trace("fd %d: scheduling to check if connect finished in %dms second", sock, interval);
+    crm_trace("Scheduling check in %dms for whether connect to fd %d finished",
+              interval, sock);
     timer = g_timeout_add(interval, check_connect_finished, cb_data);
     if (timer_id) {
         *timer_id = timer;
@@ -821,18 +821,16 @@ internal_tcp_connect_async(int sock,
 static int
 internal_tcp_connect(int sock, const struct sockaddr *addr, socklen_t addrlen)
 {
-    int flag = 0;
     int rc = connect(sock, addr, addrlen);
 
     if (rc == 0) {
-        if ((flag = fcntl(sock, F_GETFL)) >= 0) {
-            if (fcntl(sock, F_SETFL, flag | O_NONBLOCK) < 0) {
-                crm_err("fcntl() write failed");
-                return -1;
-            }
+        int flag = fcntl(sock, F_GETFL);
+
+        if ((flag >= 0) && (fcntl(sock, F_SETFL, flag | O_NONBLOCK) < 0)) {
+            crm_perror(LOG_WARNING, "setting socket non-blocking");
+            rc = -1;
         }
     }
-
     return rc;
 }
 
@@ -854,24 +852,23 @@ crm_remote_tcp_connect_async(const char *host, int port, int timeout, /*ms */
     int ret_ga;
     int sock = -1;
 
-    /* getaddrinfo */
+    // Get host's IP address(es)
     memset(&hints, 0, sizeof(struct addrinfo));
     hints.ai_family = AF_UNSPEC;        /* Allow IPv4 or IPv6 */
     hints.ai_socktype = SOCK_STREAM;
     hints.ai_flags = AI_CANONNAME;
-
-    crm_debug("Looking up %s", server);
     ret_ga = getaddrinfo(server, NULL, &hints, &res);
     if (ret_ga) {
-        crm_err("getaddrinfo: %s", gai_strerror(ret_ga));
-        return -1;
+        crm_err("Unable to get IP address info for %s: %s",
+                server, gai_strerror(ret_ga));
+        goto async_cleanup;
     }
-
     if (!res || !res->ai_addr) {
-        crm_err("getaddrinfo failed");
+        crm_err("Unable to get IP address info for %s: no result", server);
         goto async_cleanup;
     }
 
+    // getaddrinfo() returns a list of host's addresses, try them in order
     for (rp = res; rp != NULL; rp = rp->ai_next) {
         struct sockaddr *addr = rp->ai_addr;
 
@@ -882,12 +879,12 @@ crm_remote_tcp_connect_async(const char *host, int port, int timeout, /*ms */
         if (rp->ai_canonname) {
             server = res->ai_canonname;
         }
-        crm_debug("Got address %s for %s", server, host);
+        crm_debug("Got canonical name %s for %s", server, host);
 
-        /* create socket */
         sock = socket(rp->ai_family, SOCK_STREAM, IPPROTO_TCP);
         if (sock == -1) {
-            crm_err("Socket creation failed for remote client connection.");
+            crm_perror(LOG_WARNING, "creating socket for connection to %s",
+                       server);
             continue;
         }
 
@@ -901,7 +898,7 @@ crm_remote_tcp_connect_async(const char *host, int port, int timeout, /*ms */
 
         memset(buffer, 0, DIMOF(buffer));
         crm_sockaddr2str(addr, buffer);
-        crm_info("Attempting to connect to remote server at %s:%d", buffer, port);
+        crm_info("Attempting TCP connection to %s:%d", buffer, port);
 
         if (callback) {
             if (internal_tcp_connect_async
@@ -909,10 +906,8 @@ crm_remote_tcp_connect_async(const char *host, int port, int timeout, /*ms */
                 goto async_cleanup; /* Success for now, we'll hear back later in the callback */
             }
 
-        } else {
-            if (internal_tcp_connect(sock, rp->ai_addr, rp->ai_addrlen) == 0) {
-                break;          /* Success */
-            }
+        } else if (internal_tcp_connect(sock, rp->ai_addr, rp->ai_addrlen) == 0) {
+            break;          /* Success */
         }
 
         close(sock);
diff --git a/lib/lrmd/lrmd_client.c b/lib/lrmd/lrmd_client.c
index 886047208..828133bc3 100644
--- a/lib/lrmd/lrmd_client.c
+++ b/lib/lrmd/lrmd_client.c
@@ -1133,7 +1133,7 @@ lrmd_tcp_connect_cb(void *userdata, int sock)
 {
     lrmd_t *lrmd = userdata;
     lrmd_private_t *native = lrmd->private;
-    char name[256] = { 0, };
+    char *name;
     static struct mainloop_fd_callbacks lrmd_tls_callbacks = {
         .dispatch = lrmd_tls_dispatch,
         .destroy = lrmd_tls_connection_destroy,
@@ -1145,19 +1145,22 @@ lrmd_tcp_connect_cb(void *userdata, int sock)
 
     if (rc < 0) {
         lrmd_tls_connection_destroy(lrmd);
-        crm_info("remote lrmd connect to %s at port %d failed", native->server, native->port);
+        crm_info("Could not connect to remote LRMD at %s:%d",
+                 native->server, native->port);
         report_async_connection_result(lrmd, rc);
         return;
     }
 
-    /* TODO continue with tls stuff now that tcp connect passed. make this async as well soon
-     * to avoid all blocking code in the client. */
+    /* The TCP connection was successful, so establish the TLS connection.
+     * @TODO make this async to avoid blocking code in client
+     */
+
     native->sock = sock;
 
     rc = lrmd_tls_set_key(&psk_key);
     if (rc != 0) {
-        crm_warn("Setup of the key failed (rc=%d) for remote node %s:%d",
-                 rc, native->server, native->port);
+        crm_warn("Could not set key for remote LRMD at %s:%d " CRM_XS " rc=%d",
+                 native->server, native->port, rc);
         lrmd_tls_connection_destroy(lrmd);
         report_async_connection_result(lrmd, rc);
         return;
@@ -1170,8 +1173,8 @@ lrmd_tcp_connect_cb(void *userdata, int sock)
     native->remote->tls_session = create_psk_tls_session(sock, GNUTLS_CLIENT, native->psk_cred_c);
 
     if (crm_initiate_client_tls_handshake(native->remote, LRMD_CLIENT_HANDSHAKE_TIMEOUT) != 0) {
-        crm_warn("Client tls handshake failed for server %s:%d. Disconnecting", native->server,
-                 native->port);
+        crm_warn("Disconnecting after TLS handshake with remote LRMD %s:%d failed",
+                 native->server, native->port);
         gnutls_deinit(*native->remote->tls_session);
         gnutls_free(native->remote->tls_session);
         native->remote->tls_session = NULL;
@@ -1180,42 +1183,38 @@ lrmd_tcp_connect_cb(void *userdata, int sock)
         return;
     }
 
-    crm_info("Remote lrmd client TLS connection established with server %s:%d", native->server,
-             native->port);
+    crm_info("TLS connection to remote LRMD %s:%d succeeded",
+             native->server, native->port);
 
-    snprintf(name, 128, "remote-lrmd-%s:%d", native->server, native->port);
+    name = crm_strdup_printf("remote-lrmd-%s:%d", native->server, native->port);
 
     native->process_notify = mainloop_add_trigger(G_PRIORITY_HIGH, lrmd_tls_dispatch, lrmd);
     native->source =
         mainloop_add_fd(name, G_PRIORITY_HIGH, native->sock, lrmd, &lrmd_tls_callbacks);
 
     rc = lrmd_handshake(lrmd, name);
-    report_async_connection_result(lrmd, rc);
+    free(name);
 
+    report_async_connection_result(lrmd, rc);
     return;
 }
 
 static int
 lrmd_tls_connect_async(lrmd_t * lrmd, int timeout /*ms */ )
 {
-    int rc = -1;
     int sock = 0;
     int timer_id = 0;
-
     lrmd_private_t *native = lrmd->private;
 
     lrmd_gnutls_global_init();
-
-    sock = crm_remote_tcp_connect_async(native->server, native->port, timeout, &timer_id, lrmd,
-                                      lrmd_tcp_connect_cb);
-
-    if (sock != -1) {
-        native->sock = sock;
-        rc = 0;
-        native->async_timer = timer_id;
+    sock = crm_remote_tcp_connect_async(native->server, native->port, timeout,
+                                        &timer_id, lrmd, lrmd_tcp_connect_cb);
+    if (sock < 0) {
+        return sock;
     }
-
-    return rc;
+    native->sock = sock;
+    native->async_timer = timer_id;
+    return pcmk_ok;
 }
 
 static int
@@ -1267,12 +1266,13 @@ lrmd_tls_connect(lrmd_t * lrmd, int *fd)
     if (fd) {
         *fd = sock;
     } else {
-        char name[256] = { 0, };
-        snprintf(name, 128, "remote-lrmd-%s:%d", native->server, native->port);
+        char *name = crm_strdup_printf("remote-lrmd-%s:%d",
+                                       native->server, native->port);
 
         native->process_notify = mainloop_add_trigger(G_PRIORITY_HIGH, lrmd_tls_dispatch, lrmd);
         native->source =
             mainloop_add_fd(name, G_PRIORITY_HIGH, native->sock, lrmd, &lrmd_tls_callbacks);
+        free(name);
     }
     return pcmk_ok;
 }
