log: Improve the logging function.

include/libssh/libssh.h

@@ -407,7 +407,12 @@ LIBSSH_API int ssh_init(void);
 LIBSSH_API int ssh_is_blocking(ssh_session session);
 LIBSSH_API int ssh_is_connected(ssh_session session);
 LIBSSH_API int ssh_is_server_known(ssh_session session);
-LIBSSH_API void ssh_log(ssh_session session, int prioriry, const char *format, ...) PRINTF_ATTRIBUTE(3, 4);
+
+/* legacy */
+LIBSSH_API void ssh_log(ssh_session session,
+                        int prioriry,
+                        const char *format, ...) PRINTF_ATTRIBUTE(3, 4);
+
 LIBSSH_API ssh_channel ssh_message_channel_request_open_reply_accept(ssh_message msg);
 LIBSSH_API int ssh_message_channel_request_reply_success(ssh_message msg);
 LIBSSH_API void ssh_message_free(ssh_message msg);

include/libssh/priv.h

@@ -263,6 +263,14 @@ int ssh_options_apply(ssh_session session);
 /* server.c */
 SSH_PACKET_CALLBACK(ssh_packet_kexdh_init);
 
+/* LOGGING */
+#define SSH_LOG(session, priority, ...) \
+    _ssh_log(session, priority, __FUNCTION__, __VA_ARGS__)
+void ssh_log_function(ssh_session session,
+                      int prioriry,
+                      const char *function,
+                      const char *format, ...) PRINTF_ATTRIBUTE(4, 5);
+
 /** Free memory space */
 #define SAFE_FREE(x) do { if ((x) != NULL) {free(x); x=NULL;} } while(0)
 

src/log.c

@@ -24,8 +24,10 @@
 #include <stdio.h>
 #include <stdarg.h>
 #include <string.h>
+#include <sys/time.h>
 
 #include "libssh/priv.h"
+#include "libssh/misc.h"
 #include "libssh/session.h"
 
 /**
@@ -37,43 +39,69 @@
  * @{
  */
 
+static int current_timestring(int hires, char *buf, size_t len)
+{
+    char tbuf[64];
+    struct timeval tv;
+    struct tm *tm;
+    time_t t;
+
+    gettimeofday(&tv, NULL);
+    t = (time_t) tv.tv_sec;
+
+    tm = localtime(&t);
+    if (tm == NULL) {
+        return -1;
+    }
+
+    if (hires) {
+        strftime(tbuf, sizeof(tbuf) - 1, "%Y/%m/%d %H:%M:%S", tm);
+        snprintf(buf, len, "%s.%06ld", tbuf, tv.tv_usec);
+    } else {
+        strftime(tbuf, sizeof(tbuf) - 1, "%Y/%m/%d %H:%M:%S", tm);
+        snprintf(buf, len, "%s", tbuf);
+    }
+
+    return 0;
+}
+
 /** @internal
  * @brief do the actual work of logging an event
  */
 
-static void do_ssh_log(struct ssh_common_struct *common, int verbosity,
-    const char *buffer){
-  char indent[256];
-  int min;
+static void do_ssh_log(struct ssh_common_struct *common,
+                       int verbosity,
+                       const char *function,
+                       const char *buffer) {
+    char date[64] = {0};
+    int rc;
+
     if (common->callbacks && common->callbacks->log_function) {
-    common->callbacks->log_function((ssh_session)common, verbosity, buffer,
+        char buf[1024];
+
+        snprintf(buf, sizeof(buf), "%s: %s", function, buf);
+
+        common->callbacks->log_function((ssh_session)common,
+                                        verbosity,
+                                        buf,
                                         common->callbacks->userdata);
-  } else if (verbosity == SSH_LOG_FUNCTIONS) {
-    if (common->log_indent > 255) {
-      min = 255;
-    } else {
-      min = common->log_indent;
+        return;
     }
 
-    memset(indent, ' ', min);
-    indent[min] = '\0';
-
-    fprintf(stderr, "[func] %s%s\n", indent, buffer);
+    rc = current_timestring(1, date, sizeof(date));
+    if (rc == 0) {
+        fprintf(stderr, "[%s, %d] %s\n", date, verbosity, function);
     } else {
-    fprintf(stderr, "[%d] %s\n", verbosity, buffer);
+        fprintf(stderr, "[%d] %s\n", verbosity, function);
     }
+    fprintf(stderr, "  %s\n", buffer);
 }
 
-/**
- * @brief Log a SSH event.
- *
- * @param session       The SSH session.
- *
- * @param verbosity     The verbosity of the event.
- *
- * @param format        The format string of the log entry.
- */
-void ssh_log(ssh_session session, int verbosity, const char *format, ...) {
+/* legacy function */
+void ssh_log(ssh_session session,
+             int verbosity,
+             const char *format, ...)
+{
   char buffer[1024];
   va_list va;
 
@@ -81,7 +109,23 @@ void ssh_log(ssh_session session, int verbosity, const char *format, ...) {
     va_start(va, format);
     vsnprintf(buffer, sizeof(buffer), format, va);
     va_end(va);
-    do_ssh_log(&session->common, verbosity, buffer);
+    do_ssh_log(&session->common, verbosity, "", buffer);
+  }
+}
+
+void ssh_log_function(ssh_session session,
+                      int verbosity,
+                      const char *function,
+                      const char *format, ...)
+{
+  char buffer[1024];
+  va_list va;
+
+  if (verbosity <= session->common.log_verbosity) {
+    va_start(va, format);
+    vsnprintf(buffer, sizeof(buffer), format, va);
+    va_end(va);
+    do_ssh_log(&session->common, verbosity, function, buffer);
   }
 }
 
@@ -99,7 +143,7 @@ void ssh_log_common(struct ssh_common_struct *common, int verbosity, const char
     va_start(va, format);
     vsnprintf(buffer, sizeof(buffer), format, va);
     va_end(va);
-    do_ssh_log(common, verbosity, buffer);
+    do_ssh_log(common, verbosity, "common", buffer);
   }
 }