improve logs

Change-Id: I487f1720ca137a5104ec85ba8d8aaec5aae05d3b
Reviewed-on: https://review.couchbase.org/c/libcouchbase/+/197288
Reviewed-by: Brett Lawson <brett19@gmail.com>
Tested-by: Build Bot <build@couchbase.com>

Author: avsej

contrib/cbsasl/src/cram-md5/md5.h

@@ -28,6 +28,10 @@
 #elif !defined(_MD5_H)
 #define _MD5_H
 
+#ifdef __cplusplus
+extern "C" {
+#endif
+
 /* Any 32-bit or wider unsigned integer data type will do */
 typedef unsigned int MD5_u32plus;
 
@@ -42,4 +46,8 @@ extern void cbsasl_MD5_Init(MD5_CTX *ctx);
 extern void cbsasl_MD5_Update(MD5_CTX *ctx, void *data, unsigned long size);
 extern void cbsasl_MD5_Final(unsigned char *result, MD5_CTX *ctx);
 
+#ifdef __cplusplus
+}
+#endif
+
 #endif

contrib/cbsasl/src/util.h

@@ -18,6 +18,10 @@
 #define CBSASL_UTIL_H_ 1
 #include <config.h>
 
+#ifdef __cplusplus
+extern "C" {
+#endif
+
 /* Encode hexadecimal representation of bytes from src into dest.
  * Will write srclen * 2 bytes. */
 void cbsasl_hex_encode(char *dest, const char *src, size_t srclen);
@@ -27,5 +31,8 @@ int cbsasl_secure_compare(const char *a, size_t alen, const char *b, size_t blen
 
 cbsasl_error_t cbsasl_secure_random(char *dest, size_t len);
 
+#ifdef __cplusplus
+}
+#endif
 
 #endif /*  CBSASL_UTIL_H_ */

example/db/dbx.cc

@@ -129,13 +129,20 @@ static void get_callback(lcb_INSTANCE *instance, int, const lcb_RESPGET *resp)
 
     rc = lcb_respget_status(resp);
     if (rc != LCB_SUCCESS) {
+        const lcb_KEY_VALUE_ERROR_CONTEXT *ctx{};
+        lcb_respget_error_context(resp, &ctx);
+        const char *endpoint{};
+        size_t endpoint_length{};
+        if (ctx != nullptr) {
+            lcb_errctx_kv_endpoint(ctx, &endpoint, &endpoint_length);
+        }
         if (rc == LCB_ERR_DOCUMENT_NOT_FOUND) {
             std::cerr << "unable to get \"" << std::string(key, key_len) << "\". rc: " << lcb_strerror_short(rc)
-                      << ". Creating new document\n";
+                      << ", endpoint: " << std::string(endpoint, endpoint_length) << ". Creating new document\n";
             upsert_key(instance, key, key_len);
         } else {
             std::cerr << "unable to get \"" << std::string(key, key_len) << "\". rc: " << lcb_strerror_short(rc)
-                      << "\n";
+                      << ", endpoint: " << std::string(endpoint, endpoint_length) << "\n";
         }
     }
 

src/bucketconfig/bc_cccp.cc

@@ -202,9 +202,9 @@ lcb_STATUS CccpProvider::expect_config_with_version(const lcb_host_t *origin, co
          */
         lcb_log(LOGARGS(this, TRACE),
                 "Ignore configuration request " LCB_HOST_FMT ": expected=%" PRId64 ":%" PRId64 ", current=%" PRId64
-                ":%" PRId64 ", requested=%" PRId64 ":%" PRId64,
+                ":%" PRId64 ", requested=%" PRId64 ":%" PRId64 ", has_pending_request=%d",
                 LCB_HOST_ARG(parent->settings, origin), previous_expected.epoch, previous_expected.revision,
-                current.epoch, current.revision, requested.epoch, requested.revision);
+                current.epoch, current.revision, requested.epoch, requested.revision, has_pending_request());
     }
     return LCB_SUCCESS;
 }
@@ -423,8 +423,7 @@ static void on_connected(lcbio_SOCKET *sock, void *data, lcb_STATUS err, lcbio_O
 
     ioprocs.cb_err = io_error_handler;
     ioprocs.cb_read = io_read_handler;
-    cccp->ioctx = lcbio_ctx_new(sock, data, &ioprocs);
-    cccp->ioctx->subsys = "bc_cccp";
+    cccp->ioctx = lcbio_ctx_new(sock, data, &ioprocs, "bc_cccp");
     sock->service = LCBIO_SERVICE_CFG;
     cccp->request_config();
 }

src/bucketconfig/bc_http.cc

@@ -326,8 +326,7 @@ static void on_connected(lcbio_SOCKET *sock, void *arg, lcb_STATUS err, lcbio_OS
 
     procs.cb_err = io_error_handler;
     procs.cb_read = read_common;
-    http->ioctx = lcbio_ctx_new(sock, http, &procs);
-    http->ioctx->subsys = "bc_http";
+    http->ioctx = lcbio_ctx_new(sock, http, &procs, "bc_http");
     sock->service = LCBIO_SERVICE_CFG;
 
     lcbio_ctx_put(http->ioctx, http->request_buf.c_str(), http->request_buf.size());

src/http/http_io.cc

@@ -253,9 +253,8 @@ static void on_connected(lcbio_SOCKET *sock, void *arg, lcb_STATUS err, lcbio_OS
 
     procs.cb_err = io_error;
     procs.cb_read = io_read;
-    req->ioctx = lcbio_ctx_new(sock, arg, &procs);
+    req->ioctx = lcbio_ctx_new(sock, arg, &procs, "mgmt/capi");
     sock->service = service;
-    req->ioctx->subsys = "mgmt/capi";
     lcbio_ctx_put(req->ioctx, &req->preamble[0], req->preamble.size());
     if (!req->body.empty()) {
         lcbio_ctx_put(req->ioctx, &req->body[0], req->body.size());

src/lcbio/connect.cc

@@ -203,6 +203,9 @@ void Connstart::state_signal(State next_state, lcb_STATUS err)
     } else if (last_error == LCB_SUCCESS) {
         /* set error code only if previous code was not a failure */
         last_error = err;
+    } else {
+        lcb_log(LOGARGS_T(DEBUG), CSLOGFMT "Do not override last_error. current: %s, new: %s", CSLOGID_T(),
+                lcb_strerror_short(last_error), lcb_strerror_short(err));
     }
 
     state = next_state;

src/lcbio/ctx.cc

@@ -64,7 +64,7 @@ static lcb_STATUS convert_lcberr(const lcbio_CTX *ctx, lcbio_IOSTATUS status)
     }
 }
 
-lcbio_CTX *lcbio_ctx_new(lcbio_SOCKET *sock, void *data, const lcbio_CTXPROCS *procs)
+lcbio_CTX *lcbio_ctx_new(lcbio_SOCKET *sock, void *data, const lcbio_CTXPROCS *procs, const char *subsys)
 {
     auto *ctx = new lcbio_CTX{};
     ctx->sock = sock;
@@ -74,7 +74,7 @@ lcbio_CTX *lcbio_ctx_new(lcbio_SOCKET *sock, void *data, const lcbio_CTXPROCS *p
     ctx->procs = *procs;
     ctx->state = ES_ACTIVE;
     ctx->as_err = lcbio_timer_new(ctx->io, ctx, err_handler);
-    ctx->subsys = "unknown";
+    ctx->subsys = subsys == nullptr ? "unknown" : subsys;
     sock->service = LCBIO_SERVICE_UNSPEC;
     sock->atime = LCB_NS2US(gethrtime());
 
@@ -361,7 +361,7 @@ static void Cr_handler(lcb_sockdata_t *sd, lcb_ssize_t nr, void *arg)
                 {
                     char *b64 = nullptr;
                     lcb_SIZE nb64 = 0;
-                    char *buf = calloc(total, sizeof(char));
+                    char *buf = (char *)calloc(total, sizeof(char));
                     rdb_copyread(&ctx->ior, buf, total);
                     lcb_base64_encode2(buf, total, &b64, &nb64);
                     lcb_log(LOGARGS(ctx, TRACE), CTX_LOGFMT "pkt,rcv: size=%d, %.*s", CTX_LOGID(ctx), (int)nb64,

src/lcbio/ctx.h

@@ -167,7 +167,7 @@ typedef struct lcbio_CTX {
  * @param procs callback table
  * @return a new context object.
  */
-lcbio_CTX *lcbio_ctx_new(lcbio_SOCKET *sock, void *data, const lcbio_CTXPROCS *procs);
+lcbio_CTX *lcbio_ctx_new(lcbio_SOCKET *sock, void *data, const lcbio_CTXPROCS *procs, const char *subsys);
 
 /**
  * Callback invoked when the connection is about to be release

src/lcbio/manager.cc

@@ -326,8 +326,8 @@ void PoolRequest::invoke()
         PoolConnInfo *info = PoolConnInfo::from_sock(sock);
         info->set_leased();
         state = ASSIGNED;
-        lcb_log(LOGARGS(info->parent->parent, DEBUG), HE_LOGFMT "Assigning R=%p SOCKET=%p", HE_LOGID(info->parent),
-                (void *)this, (void *)sock);
+        lcb_log(LOGARGS(info->parent->parent, DEBUG), HE_LOGFMT "Assigning R=%p SOCKET=%p, SOCK=%016" PRIx64,
+                HE_LOGID(info->parent), (void *)this, (void *)sock, sock->id);
     }
 
     callback(sock, arg, err, 0);